Dec 15 14:24:00 adminvascosilva sudo[6222]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 15 14:24:00 adminvascosilva sudo[6222]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:24:00 adminvascosilva sudo[6224]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 15 14:24:00 adminvascosilva sudo[6224]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:24:00 adminvascosilva sudo[6224]: pam_unix(sudo:session): session closed for user root Dec 15 14:24:00 adminvascosilva sudo[6222]: pam_unix(sudo:session): session closed for user root Dec 15 14:24:00 adminvascosilva sudo[6226]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Dec 15 14:24:00 adminvascosilva sudo[6226]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:24:00 adminvascosilva sudo[6226]: pam_unix(sudo:session): session closed for user root Dec 15 14:24:00 adminvascosilva volumio[5986]: info: Upmpdcli Daemon Started Dec 15 14:24:02 adminvascosilva go-librespot[6165]: time="2025-12-15T14:24: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:24:02 adminvascosilva systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 14:24:02 adminvascosilva systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 14:24:02 adminvascosilva sudo[6236]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 15 14:24:02 adminvascosilva sudo[6236]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:24:02 adminvascosilva sudo[6238]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 15 14:24:02 adminvascosilva sudo[6238]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:24:02 adminvascosilva systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Dec 15 14:24:02 adminvascosilva systemd[1]: mpd_monitor.service: Deactivated successfully. Dec 15 14:24:02 adminvascosilva systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Dec 15 14:24:02 adminvascosilva systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Dec 15 14:24:02 adminvascosilva sudo[6236]: pam_unix(sudo:session): session closed for user root Dec 15 14:24:02 adminvascosilva mpd_monitor.sh[6241]: MPD Monitor Service: Starting MPD Monitor Service Dec 15 14:24:02 adminvascosilva sudo[6238]: pam_unix(sudo:session): session closed for user root Dec 15 14:24:02 adminvascosilva volumio[5986]: info: Successfully started MPD Monitor Dec 15 14:24:02 adminvascosilva volumio[5986]: info: Successfully started MPD Monitor Dec 15 14:24:02 adminvascosilva volumio[5986]: info: Initializing connection to go-librespot Websocket Dec 15 14:24:02 adminvascosilva volumio[5986]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 15 14:24:04 adminvascosilva volumio[5986]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Dec 15 14:24:05 adminvascosilva systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Dec 15 14:24:05 adminvascosilva systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:24:05 adminvascosilva systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:24:05 adminvascosilva go-librespot[6247]: go-librespot daemon starting... Dec 15 14:24:05 adminvascosilva go-librespot[6248]: time="2025-12-15T14:24:05Z" level=info msg="running go-librespot 0.4.0" Dec 15 14:24:05 adminvascosilva go-librespot[6248]: time="2025-12-15T14:24:05Z" level=debug msg="app state loaded" Dec 15 14:24:05 adminvascosilva go-librespot[6248]: time="2025-12-15T14:24:05Z" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 14:24:05 adminvascosilva go-librespot[6248]: time="2025-12-15T14:24:05Z" 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:24:05 adminvascosilva go-librespot[6248]: time="2025-12-15T14:24:05Z" 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:24:05 adminvascosilva go-librespot[6248]: time="2025-12-15T14:24:05Z" 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:24:05 adminvascosilva go-librespot[6248]: time="2025-12-15T14:24:05Z" level=info msg="zeroconf server listening on port 44075" Dec 15 14:24:05 adminvascosilva go-librespot[6248]: time="2025-12-15T14:24:05Z" level=debug msg="obtained new client token: AAAHqsptEjGaafR1kGy5wT8rKXyzKjEbe3Y5kR7fVWDlyt4A3lVkpHe2VwelhEslCnalnfb5fGOSxXSZEfZ4oTvNbsxc0w2bo8vLEnq8t24VE2JQcA8xMDcIHnx5VSWLa7VP7/8bNJa766zqYEYHHdLVDloqiquXwv7Z0vWx0SstSF1lakTDtzuFpQpAkSW1ZJ4369pqOC4BsgPioBYLhO3vAFyeA9TZPDHdlQhAst12O1tSvnF9qA==" Dec 15 14:24:05 adminvascosilva go-librespot[6248]: time="2025-12-15T14:24:05Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Dec 15 14:24:05 adminvascosilva go-librespot[6248]: time="2025-12-15T14:24:05Z" level=debug msg="completed keyexchange" Dec 15 14:24:05 adminvascosilva go-librespot[6248]: time="2025-12-15T14:24:05Z" level=debug msg="completed challenge" Dec 15 14:24:05 adminvascosilva go-librespot[6248]: time="2025-12-15T14:24: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:24:05 adminvascosilva systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 14:24:05 adminvascosilva systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 14:24:05 adminvascosilva volumio[5986]: info: Initializing connection to go-librespot Websocket Dec 15 14:24:05 adminvascosilva volumio[5986]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 15 14:24:07 adminvascosilva volumio[5986]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Dec 15 14:24:07 adminvascosilva volumio[5986]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Dec 15 14:24:07 adminvascosilva volumio[5986]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Dec 15 14:24:07 adminvascosilva volumio[5986]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Dec 15 14:24:07 adminvascosilva volumio[5986]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Dec 15 14:24:07 adminvascosilva volumio[5986]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Dec 15 14:24:07 adminvascosilva volumio[5986]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Dec 15 14:24:07 adminvascosilva volumio[5986]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Dec 15 14:24:07 adminvascosilva volumio[5986]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Dec 15 14:24:07 adminvascosilva volumio[5986]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Dec 15 14:24:07 adminvascosilva volumio[5986]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Dec 15 14:24:07 adminvascosilva volumio[5986]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Dec 15 14:24:07 adminvascosilva volumio[5986]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Dec 15 14:24:07 adminvascosilva volumio[5986]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Dec 15 14:24:07 adminvascosilva volumio[5986]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Dec 15 14:24:07 adminvascosilva volumio[5986]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Dec 15 14:24:07 adminvascosilva volumio[5986]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Dec 15 14:24:07 adminvascosilva volumio[5986]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Dec 15 14:24:07 adminvascosilva volumio[5986]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Dec 15 14:24:07 adminvascosilva volumio[5986]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Dec 15 14:24:07 adminvascosilva volumio[5986]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Dec 15 14:24:07 adminvascosilva volumio[5986]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Dec 15 14:24:07 adminvascosilva volumio[5986]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Dec 15 14:24:07 adminvascosilva volumio[5986]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Dec 15 14:24:07 adminvascosilva volumio[5986]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Dec 15 14:24:07 adminvascosilva volumio[5986]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Dec 15 14:24:07 adminvascosilva volumio[5986]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Dec 15 14:24:07 adminvascosilva volumio[5986]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Dec 15 14:24:07 adminvascosilva volumio[5986]: info: Adding plugin bluetooth to MyMusic Plugins Dec 15 14:24:07 adminvascosilva volumio[5986]: info: Adding plugin multiroom to MyMusic Plugins Dec 15 14:24:07 adminvascosilva volumio[5986]: info: Adding plugin metavolumio to MyMusic Plugins Dec 15 14:24:07 adminvascosilva volumio[5986]: info: Adding plugin cd_controller to MyMusic Plugins Dec 15 14:24:07 adminvascosilva volumio[5986]: info: Adding plugin qobuzconnect to MyMusic Plugins Dec 15 14:24:07 adminvascosilva volumio[5986]: info: Adding plugin smart_inputs to MyMusic Plugins Dec 15 14:24:07 adminvascosilva volumio[5986]: info: Adding plugin tidalconnect to MyMusic Plugins Dec 15 14:24:07 adminvascosilva volumio[5986]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Dec 15 14:24:08 adminvascosilva volumio[5986]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Dec 15 14:24:08 adminvascosilva volumio[5986]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Dec 15 14:24:08 adminvascosilva volumio[5986]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:24:08 adminvascosilva volumio[5986]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:24:08 adminvascosilva volumio[5986]: info: Starting MyVolumio Remote Streaming Endpoints Dec 15 14:24:08 adminvascosilva volumio[5986]: info: MyVolumio login type: Token Dec 15 14:24:08 adminvascosilva volumio[5986]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Dec 15 14:24:08 adminvascosilva volumio[5986]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Dec 15 14:24:08 adminvascosilva systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Dec 15 14:24:08 adminvascosilva systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:24:08 adminvascosilva systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:24:08 adminvascosilva go-librespot[6255]: go-librespot daemon starting... Dec 15 14:24:08 adminvascosilva go-librespot[6256]: time="2025-12-15T14:24:08Z" level=info msg="running go-librespot 0.4.0" Dec 15 14:24:08 adminvascosilva go-librespot[6256]: time="2025-12-15T14:24:08Z" level=debug msg="app state loaded" Dec 15 14:24:08 adminvascosilva go-librespot[6256]: time="2025-12-15T14:24:08Z" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 14:24:09 adminvascosilva go-librespot[6256]: time="2025-12-15T14:24:09Z" 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:24:09 adminvascosilva go-librespot[6256]: time="2025-12-15T14:24:09Z" 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:24:09 adminvascosilva go-librespot[6256]: time="2025-12-15T14:24:09Z" 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:24:09 adminvascosilva go-librespot[6256]: time="2025-12-15T14:24:09Z" level=info msg="zeroconf server listening on port 42125" Dec 15 14:24:09 adminvascosilva go-librespot[6256]: time="2025-12-15T14:24:09Z" level=debug msg="obtained new client token: AADIyUtXUoaeV3opvAorE9y6hE9mZMmVV8AXxE06m0bSktcu4Tb+LSSh5rDSsKO9MRvfj4Fgwzl6WIzx5k7ZG7ikvjkjybmB4c5ScAWJ/aytoPW7Mvzb+bWO8Q7LMw20jlqdDHfzb3StJECHq9zQZ8OvUfRbaNeNq0pKeXkwb2o1gpm4LLx69UobDLCNmU5dyZknkb2pOWUgLPXz7QOodsqd6NzD+BWmOhIKiz3OQKGgfo28iDw71w==" Dec 15 14:24:09 adminvascosilva go-librespot[6256]: time="2025-12-15T14:24:09Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Dec 15 14:24:09 adminvascosilva go-librespot[6256]: time="2025-12-15T14:24:09Z" level=debug msg="completed keyexchange" Dec 15 14:24:09 adminvascosilva go-librespot[6256]: time="2025-12-15T14:24:09Z" level=debug msg="completed challenge" Dec 15 14:24:09 adminvascosilva volumio[5986]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Dec 15 14:24:09 adminvascosilva volumio[5986]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Dec 15 14:24:09 adminvascosilva volumio[5986]: info: Streaming services startup Dec 15 14:24:09 adminvascosilva volumio[5986]: info: Starting Streaming Daemon Dec 15 14:24:09 adminvascosilva sudo[6264]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Dec 15 14:24:09 adminvascosilva sudo[6264]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:24:09 adminvascosilva volumio[5986]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Dec 15 14:24:09 adminvascosilva sudo[6264]: pam_unix(sudo:session): session closed for user root Dec 15 14:24:09 adminvascosilva volumio[5986]: info: Initializing connection to go-librespot Websocket Dec 15 14:24:09 adminvascosilva volumio[5986]: error: Cannot start Volumio Streaming Daemon Dec 15 14:24:09 adminvascosilva volumio[5986]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Dec 15 14:24:09 adminvascosilva volumio[5986]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Dec 15 14:24:09 adminvascosilva go-librespot[6256]: time="2025-12-15T14:24:09Z" level=debug msg="new websocket client" Dec 15 14:24:09 adminvascosilva volumio[5986]: info: Connection to go-librespot Websocket established Dec 15 14:24:10 adminvascosilva volumio[5986]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Dec 15 14:24:10 adminvascosilva volumio[5986]: info: MyVolumio token set successfully Dec 15 14:24:10 adminvascosilva volumio[5986]: info: MYVOLUMIO: Adding device Dec 15 14:24:10 adminvascosilva volumio[5986]: info: MYVOLUMIO: Evaluating Server Dec 15 14:24:11 adminvascosilva volumio[5986]: info: MyVolumio status changed Dec 15 14:24:11 adminvascosilva volumio[5986]: info: Streaming services startup Dec 15 14:24:11 adminvascosilva volumio[5986]: info: Starting Streaming Daemon Dec 15 14:24:11 adminvascosilva volumio[5986]: info: Removing browser output: myVolumio user plan is not superstar Dec 15 14:24:11 adminvascosilva volumio[5986]: info: Removing audio output: Dec 15 14:24:11 adminvascosilva volumio[5986]: info: Stoppping Tunnel 1 Dec 15 14:24:11 adminvascosilva sudo[6305]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Dec 15 14:24:11 adminvascosilva sudo[6305]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:24:11 adminvascosilva sudo[6305]: pam_unix(sudo:session): session closed for user root Dec 15 14:24:11 adminvascosilva sudo[6308]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Dec 15 14:24:11 adminvascosilva sudo[6308]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:24:11 adminvascosilva volumio[5986]: error: Cannot start Volumio Streaming Daemon Dec 15 14:24:11 adminvascosilva volumio[5986]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Dec 15 14:24:11 adminvascosilva volumio[5986]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Dec 15 14:24:11 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:24:11 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:24:11 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:24:11 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:24:11 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:24:11 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:24:11 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:24:11 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:24:11 adminvascosilva sudo[6308]: pam_unix(sudo:session): session closed for user root Dec 15 14:24:11 adminvascosilva volumio[5986]: info: Remote SSH Stopped Dec 15 14:24:11 adminvascosilva volumio[5986]: info: Setting Geolocation for MyVolumio to eu3 Dec 15 14:24:11 adminvascosilva volumio[5986]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:24:11 adminvascosilva volumio[5986]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:24:11 adminvascosilva volumio[5986]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:24:11 adminvascosilva volumio[5986]: info: Successfully Added MyVolumio device Dec 15 14:24:12 adminvascosilva volumio[5986]: info: Updating MyVolumio device info Dec 15 14:24:12 adminvascosilva volumio[5986]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:24:12 adminvascosilva volumio[5986]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:24:12 adminvascosilva volumio[5986]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:24:12 adminvascosilva volumio[5986]: info: Getting Spotify volume Dec 15 14:24:12 adminvascosilva volumio[5986]: info: Successfully Updated MyVolumio device Dec 15 14:24:12 adminvascosilva volumio[5986]: 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:24:12 adminvascosilva volumio[5986]: info: CoreCommandRouter::volumioGetState Dec 15 14:24:12 adminvascosilva volumio[5986]: info: CorePlayQueue::getTrack 0 Dec 15 14:24:12 adminvascosilva volumio[5986]: SPOTIFY: RECEIVED VOLUMIO VOLUME 25 Dec 15 14:24:12 adminvascosilva volumio[5986]: SPOTIFY: SPOTIFY VOLUME undefined Dec 15 14:24:12 adminvascosilva volumio[5986]: SPOTIFY: VOLUMIO VOLUME 25 Dec 15 14:24:12 adminvascosilva volumio[5986]: info: Aligning Spotify Volume to Volumio Volume Dec 15 14:24:12 adminvascosilva volumio[5986]: info: CoreCommandRouter::volumioGetState Dec 15 14:24:12 adminvascosilva volumio[5986]: info: CorePlayQueue::getTrack 0 Dec 15 14:24:12 adminvascosilva volumio[5986]: info: Setting Spotify Volume from Volumio: 25 Dec 15 14:24:14 adminvascosilva volumio[5986]: SPOTIFY: SETTING SPOTIFY VOLUME 25 Dec 15 14:24:14 adminvascosilva volumio[5986]: info: Sending Spotify command with payload to local API: /player/volume Dec 15 14:24:15 adminvascosilva volumio[5986]: info: AutoStart - Plugin is starting Dec 15 14:24:15 adminvascosilva volumio[5986]: info: CoreCommandRouter::volumioGetQueue Dec 15 14:24:15 adminvascosilva volumio[5986]: info: CoreStateMachine::getQueue Dec 15 14:24:15 adminvascosilva volumio[5986]: info: CorePlayQueue::getQueue Dec 15 14:24:15 adminvascosilva volumio[5986]: info: AutoStart - start playing Dec 15 14:24:15 adminvascosilva volumio[5986]: info: AutoStart - start playing with no specific position Dec 15 14:24:15 adminvascosilva volumio[5986]: info: CoreCommandRouter::volumioPlay Dec 15 14:24:15 adminvascosilva volumio[5986]: info: CoreStateMachine::play index 0 Dec 15 14:24:15 adminvascosilva volumio[5986]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 15 14:24:15 adminvascosilva volumio[5986]: info: CoreStateMachine::stop Dec 15 14:24:15 adminvascosilva volumio[5986]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 15 14:24:15 adminvascosilva volumio[5986]: info: CoreStateMachine::play index undefined Dec 15 14:24:15 adminvascosilva volumio[5986]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 15 14:24:15 adminvascosilva volumio[5986]: info: CorePlayQueue::getTrack 0 Dec 15 14:24:15 adminvascosilva volumio[5986]: info: CoreStateMachine::startPlaybackTimer Dec 15 14:24:15 adminvascosilva volumio[5986]: info: CorePlayQueue::getTrack 0 Dec 15 14:24:15 adminvascosilva volumio[5986]: info: [1765808655738] ControllerSpotify::clearAddPlayTrack Dec 15 14:24:15 adminvascosilva volumio[5986]: info: Sending Spotify command with payload to local API: /player/play Dec 15 14:24:23 adminvascosilva volumio[5986]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Dec 15 14:24:23 adminvascosilva volumio[5986]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Dec 15 14:24:23 adminvascosilva volumio[5986]: info: CoreCommandRouter::volumioGetState Dec 15 14:24:23 adminvascosilva volumio[5986]: info: CorePlayQueue::getTrack 0 Dec 15 14:24:24 adminvascosilva go-librespot[6256]: time="2025-12-15T14:24: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:24:24 adminvascosilva systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 14:24:24 adminvascosilva systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 14:24:24 adminvascosilva volumio[5986]: error: Failed to send command to Spotify local API: /player/play: Error: socket hang up Dec 15 14:24:24 adminvascosilva volumio[5986]: error: Failed to send command to Spotify local API: /player/volume: Error: socket hang up Dec 15 14:24:24 adminvascosilva volumio[5986]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 15 14:24:24 adminvascosilva volumio[5986]: Error: socket hang up Dec 15 14:24:24 adminvascosilva volumio[5986]: at connResetException (node:internal/errors:720:14) Dec 15 14:24:24 adminvascosilva volumio[5986]: at Socket.socketOnEnd (node:_http_client:519:23) Dec 15 14:24:24 adminvascosilva volumio[5986]: at Socket.emit (node:events:526:35) Dec 15 14:24:24 adminvascosilva volumio[5986]: at endReadableNT (node:internal/streams/readable:1376:12) Dec 15 14:24:24 adminvascosilva volumio[5986]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Dec 15 14:24:24 adminvascosilva volumio[5986]: code: 'ECONNRESET', Dec 15 14:24:24 adminvascosilva volumio[5986]: response: undefined Dec 15 14:24:24 adminvascosilva volumio[5986]: } Dec 15 14:24:24 adminvascosilva volumio[5986]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 15 14:24:25 adminvascosilva sudo[6342]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-15 14:23' Dec 15 14:24:25 adminvascosilva sudo[6342]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:24:25 adminvascosilva sudo[6342]: pam_unix(sudo:session): session closed for user root Dec 15 14:24:25 adminvascosilva volumio-remote-updater[646]: [2025-12-15 14:24:25] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Dec 15 14:24:25 adminvascosilva volumio-remote-updater[646]: [2025-12-15 14:24:25] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Dec 15 14:24:25 adminvascosilva systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Dec 15 14:24:25 adminvascosilva systemd[1]: volumio.service: Failed with result 'exit-code'. Dec 15 14:24:25 adminvascosilva systemd[1]: volumio.service: Consumed 26.940s CPU time. Dec 15 14:24:25 adminvascosilva systemd[1]: Started dynamicswap.service - dynamicswap service. Dec 15 14:24:25 adminvascosilva systemd[1]: dynamicswap.service: Deactivated successfully. Dec 15 14:24:26 adminvascosilva systemd[1]: volumio.service: Scheduled restart job, restart counter is at 14. Dec 15 14:24:26 adminvascosilva systemd[1]: Started dynamicswap.service - dynamicswap service. Dec 15 14:24:26 adminvascosilva systemd[1]: Stopped volumio.service - Volumio Backend Module. Dec 15 14:24:26 adminvascosilva systemd[1]: volumio.service: Consumed 26.940s CPU time. Dec 15 14:24:26 adminvascosilva systemd[1]: Started volumio.service - Volumio Backend Module. Dec 15 14:24:26 adminvascosilva systemd[1]: dynamicswap.service: Deactivated successfully. Dec 15 14:24:27 adminvascosilva systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Dec 15 14:24:27 adminvascosilva systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:24:27 adminvascosilva systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:24:27 adminvascosilva go-librespot[6372]: go-librespot daemon starting... Dec 15 14:24:27 adminvascosilva go-librespot[6373]: time="2025-12-15T14:24:27Z" level=info msg="running go-librespot 0.4.0" Dec 15 14:24:27 adminvascosilva go-librespot[6373]: time="2025-12-15T14:24:27Z" level=debug msg="app state loaded" Dec 15 14:24:27 adminvascosilva go-librespot[6373]: time="2025-12-15T14:24:27Z" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 14:24:27 adminvascosilva go-librespot[6373]: time="2025-12-15T14:24:27Z" 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:24:27 adminvascosilva go-librespot[6373]: time="2025-12-15T14:24:27Z" 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:24:27 adminvascosilva go-librespot[6373]: time="2025-12-15T14:24:27Z" 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:24:27 adminvascosilva go-librespot[6373]: time="2025-12-15T14:24:27Z" level=info msg="zeroconf server listening on port 40109" Dec 15 14:24:28 adminvascosilva go-librespot[6373]: time="2025-12-15T14:24:28Z" level=debug msg="obtained new client token: AAD9pgxNnT9qyBe5oV9aslga1854890XHtpXKm1rZF8rq0suz2s1zIOd5NXQvt4CS2VfsXh32P3k2oCfbDZjx4GBks8mB8nOa+Bv1V7a+5qevihsWtpTNFneETZ+X0i6BP2W2ptLGyci+H0YNfWsFg2RDdISRetCowVEVj7Wz2j1nNA8ZhnQnfU1DsJ/XBY35Kx2/1G3jtCzTdY/C4VSHSt6J/z7QlbXBUhpAPdtjPJ1E4HXjNA=" Dec 15 14:24:28 adminvascosilva volumio[6357]: info: ------------------------------------------- Dec 15 14:24:28 adminvascosilva volumio[6357]: info: ----- Volumio3 ---- Dec 15 14:24:28 adminvascosilva volumio[6357]: info: ------------------------------------------- Dec 15 14:24:28 adminvascosilva volumio[6357]: info: ----- System startup ---- Dec 15 14:24:28 adminvascosilva volumio[6357]: info: ------------------------------------------- Dec 15 14:24:28 adminvascosilva go-librespot[6373]: time="2025-12-15T14:24:28Z" 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:24:28 adminvascosilva go-librespot[6373]: time="2025-12-15T14:24:28Z" level=debug msg="connected to ap-gew1.spotify.com:443" Dec 15 14:24:28 adminvascosilva go-librespot[6373]: time="2025-12-15T14:24:28Z" level=debug msg="completed keyexchange" Dec 15 14:24:28 adminvascosilva go-librespot[6373]: time="2025-12-15T14:24:28Z" level=debug msg="completed challenge" Dec 15 14:24:28 adminvascosilva go-librespot[6373]: time="2025-12-15T14:24:28Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TryAnotherAP " Dec 15 14:24:28 adminvascosilva systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 14:24:28 adminvascosilva systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 14:24:28 adminvascosilva volumio[6357]: info: MYVOLUMIO Environment detected Dec 15 14:24:28 adminvascosilva volumio[6357]: info: Plugin folders cleanup Dec 15 14:24:28 adminvascosilva volumio[6357]: info: Scanning into folder /volumio/app/plugins/ Dec 15 14:24:28 adminvascosilva volumio[6357]: info: Scanning category audio_interface Dec 15 14:24:28 adminvascosilva volumio[6357]: info: Scanning category miscellanea Dec 15 14:24:28 adminvascosilva volumio[6357]: info: Scanning category music_service Dec 15 14:24:28 adminvascosilva volumio[6357]: info: Scanning category plugins.json Dec 15 14:24:28 adminvascosilva volumio[6357]: info: Scanning category system_controller Dec 15 14:24:28 adminvascosilva volumio[6357]: info: Scanning category user_interface Dec 15 14:24:28 adminvascosilva volumio[6357]: info: Scanning into folder /data/plugins/ Dec 15 14:24:28 adminvascosilva volumio[6357]: info: Scanning category music_service Dec 15 14:24:28 adminvascosilva volumio[6357]: info: Scanning category system_controller Dec 15 14:24:28 adminvascosilva volumio[6357]: info: Plugin folders cleanup completed Dec 15 14:24:28 adminvascosilva volumio[6357]: info: ------------------------------------------- Dec 15 14:24:28 adminvascosilva volumio[6357]: info: ----- Core plugins startup ---- Dec 15 14:24:28 adminvascosilva volumio[6357]: info: ------------------------------------------- Dec 15 14:24:28 adminvascosilva volumio[6357]: info: Loading plugins from folder /volumio/app/plugins/ Dec 15 14:24:28 adminvascosilva volumio[6357]: info: Adding plugin upnp to MyMusic Plugins Dec 15 14:24:28 adminvascosilva volumio[6357]: info: Adding plugin airplay_emulation to MyMusic Plugins Dec 15 14:24:28 adminvascosilva volumio[6357]: info: Adding plugin upnp_browser to MyMusic Plugins Dec 15 14:24:28 adminvascosilva volumio[6357]: info: Loading plugins from folder /data/plugins/ Dec 15 14:24:28 adminvascosilva volumio[6357]: info: Loading plugin "system"... Dec 15 14:24:28 adminvascosilva volumio[6357]: info: Loading plugin "appearance"... Dec 15 14:24:29 adminvascosilva volumio[6357]: info: Loading plugin "network"... Dec 15 14:24:30 adminvascosilva volumio[6357]: info: Refreshing Cached IP Addresses Dec 15 14:24:30 adminvascosilva sudo[6393]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 15 14:24:30 adminvascosilva sudo[6393]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:24:30 adminvascosilva volumio[6357]: info: Loading plugin "services"... Dec 15 14:24:30 adminvascosilva sudo[6393]: pam_unix(sudo:session): session closed for user root Dec 15 14:24:30 adminvascosilva volumio[6357]: info: Loading plugin "alsa_controller"... Dec 15 14:24:30 adminvascosilva sudo[6395]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 15 14:24:30 adminvascosilva sudo[6395]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:24:30 adminvascosilva sudo[6395]: pam_unix(sudo:session): session closed for user root Dec 15 14:24:30 adminvascosilva volumio[6357]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 15 14:24:30 adminvascosilva volumio[6357]: info: Loading plugin "wizard"... Dec 15 14:24:30 adminvascosilva volumio[6357]: info: Loading plugin "networkfs"... Dec 15 14:24:30 adminvascosilva volumio[6357]: info: Starting Udev Watcher for removable devices Dec 15 14:24:30 adminvascosilva volumio[6357]: info: Ignoring mount for partition: boot Dec 15 14:24:30 adminvascosilva volumio[6357]: info: Ignoring mount for partition: volumio Dec 15 14:24:30 adminvascosilva volumio[6357]: info: Ignoring mount for partition: volumio_data Dec 15 14:24:30 adminvascosilva volumio[6357]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 15 14:24:30 adminvascosilva volumio[6357]: info: Loading plugin "volumio_command_line_client"... Dec 15 14:24:30 adminvascosilva volumio[6357]: info: Loading plugin "upnp"... Dec 15 14:24:30 adminvascosilva volumio[6357]: info: [1765808670201] Starting Upmpd Daemon Dec 15 14:24:30 adminvascosilva volumio[6357]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 15 14:24:30 adminvascosilva volumio[6357]: info: Loading plugin "my_music"... Dec 15 14:24:30 adminvascosilva volumio[6357]: info: Loading plugin "mpd"... Dec 15 14:24:30 adminvascosilva volumio[6357]: info: Plugin upnp_browser is not enabled Dec 15 14:24:30 adminvascosilva volumio[6357]: info: Loading plugin "alarm-clock"... Dec 15 14:24:30 adminvascosilva volumio[6357]: info: Plugin airplay_emulation is not enabled Dec 15 14:24:30 adminvascosilva volumio[6357]: info: Loading plugin "last_100"... Dec 15 14:24:30 adminvascosilva volumio[6357]: info: Loading plugin "webradio"... Dec 15 14:24:30 adminvascosilva volumio-remote-updater[646]: [2025-12-15 14:24:30] [connect] Successful connection Dec 15 14:24:31 adminvascosilva systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Dec 15 14:24:31 adminvascosilva systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:24:31 adminvascosilva systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:24:31 adminvascosilva go-librespot[6423]: go-librespot daemon starting... Dec 15 14:24:31 adminvascosilva go-librespot[6424]: time="2025-12-15T14:24:31Z" level=info msg="running go-librespot 0.4.0" Dec 15 14:24:31 adminvascosilva go-librespot[6424]: time="2025-12-15T14:24:31Z" level=debug msg="app state loaded" Dec 15 14:24:31 adminvascosilva go-librespot[6424]: time="2025-12-15T14:24:31Z" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 14:24:31 adminvascosilva go-librespot[6424]: time="2025-12-15T14:24:31Z" 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:24:31 adminvascosilva go-librespot[6424]: time="2025-12-15T14:24:31Z" 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:24:31 adminvascosilva go-librespot[6424]: time="2025-12-15T14:24:31Z" 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:24:31 adminvascosilva go-librespot[6424]: time="2025-12-15T14:24:31Z" level=info msg="zeroconf server listening on port 41931" Dec 15 14:24:31 adminvascosilva go-librespot[6424]: time="2025-12-15T14:24:31Z" level=debug msg="obtained new client token: AAA7RnJH0wt4zuOkt6dDoJFBBl/Om8dhqTF0wgwAPLXzB1F8nulZpdbqzDPmjn2SAdxv4hMhxEPGQz92nkH7C4Cnx4Ssi7qM+KuOawalBIly9LC7yvEYSHufRpWLalMCyvGTfgAGLQYN+QyYeok7QbOsxdaX0OkKmPGXpu5Ij2uxCFGxUbTLPqzYLacwdURiQyXksCUCVYiIIb2MELg7Iy3HdjSjvhFfSI2YwLHyA7UYzQayfKqTZA==" Dec 15 14:24:31 adminvascosilva go-librespot[6424]: time="2025-12-15T14:24:31Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Dec 15 14:24:31 adminvascosilva go-librespot[6424]: time="2025-12-15T14:24:31Z" level=debug msg="completed keyexchange" Dec 15 14:24:31 adminvascosilva go-librespot[6424]: time="2025-12-15T14:24:31Z" level=debug msg="completed challenge" Dec 15 14:24:31 adminvascosilva go-librespot[6424]: time="2025-12-15T14:24:31Z" level=info msg="authenticated AP" username="ha*******ds" Dec 15 14:24:32 adminvascosilva volumio[6357]: info: Loading plugin "i2s_dacs"... Dec 15 14:24:32 adminvascosilva volumio[6357]: info: I2S DAC not set, start Auto-detection Dec 15 14:24:32 adminvascosilva volumio[6357]: info: Loading plugin "volumiodiscovery"... Dec 15 14:24:32 adminvascosilva volumio[6357]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 15 14:24:32 adminvascosilva volumio[6357]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 15 14:24:32 adminvascosilva volumio[6357]: *** WARNING *** For more information see Dec 15 14:24:32 adminvascosilva volumio[6357]: *** 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:24:32 adminvascosilva volumio[6357]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 15 14:24:32 adminvascosilva volumio[6357]: *** WARNING *** For more information see Dec 15 14:24:32 adminvascosilva node[6357]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 15 14:24:32 adminvascosilva node[6357]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 15 14:24:32 adminvascosilva node[6357]: *** WARNING *** For more information see Dec 15 14:24:32 adminvascosilva node[6357]: *** 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:24:32 adminvascosilva node[6357]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 15 14:24:32 adminvascosilva node[6357]: *** WARNING *** For more information see Dec 15 14:24:32 adminvascosilva volumio[6357]: info: Applying required configuration parameters for plugin volumiodiscovery Dec 15 14:24:32 adminvascosilva volumio[6357]: info: Discovery: Started advertising with name: adminvascosilva Dec 15 14:24:32 adminvascosilva volumio[6357]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 15 14:24:32 adminvascosilva volumio[6357]: info: Loading plugin "spop"... Dec 15 14:24:33 adminvascosilva volumio[6357]: info: Loading plugin "autostart"... Dec 15 14:24:33 adminvascosilva volumio[6357]: info: Applying required configuration parameters for plugin autostart Dec 15 14:24:33 adminvascosilva volumio[6357]: info: AutoStart - onVolumioStart - read config.json Dec 15 14:24:33 adminvascosilva volumio[6357]: info: Loading plugin "outputs"... Dec 15 14:24:33 adminvascosilva volumio[6357]: info: Loading plugin "albumart"... Dec 15 14:24:33 adminvascosilva volumio[6357]: info: Plugin example_plugin is not enabled Dec 15 14:24:33 adminvascosilva volumio[6357]: info: Loading plugin "inputs"... Dec 15 14:24:33 adminvascosilva volumio[6357]: info: Loading plugin "updater_comm"... Dec 15 14:24:33 adminvascosilva volumio[6357]: info: Plugin mpdemulation is not enabled Dec 15 14:24:33 adminvascosilva volumio[6357]: info: Loading plugin "rest_api"... Dec 15 14:24:33 adminvascosilva volumio[6357]: info: Loading plugin "websocket"... Dec 15 14:24:33 adminvascosilva volumio[6357]: info: Starting Socket.io Server version 1.7.4 Dec 15 14:24:33 adminvascosilva volumio[6357]: info: Loading i18n strings for locale pt Dec 15 14:24:33 adminvascosilva volumio[6357]: Updating browse sources language Dec 15 14:24:33 adminvascosilva volumio[6357]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 14:24:33 adminvascosilva volumio[6357]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 15 14:24:33 adminvascosilva volumio[6357]: info: CoreCommandRouter::initPlayerControls Dec 15 14:24:33 adminvascosilva volumio[6357]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:24:33 adminvascosilva volumio[6357]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:24:33 adminvascosilva volumio[6357]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:24:33 adminvascosilva volumio[6357]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:24:33 adminvascosilva volumio[6357]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:24:33 adminvascosilva volumio[6357]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:24:33 adminvascosilva volumio[6357]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:24:33 adminvascosilva volumio[6357]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:24:33 adminvascosilva volumio[6357]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 15 14:24:33 adminvascosilva volumio[6357]: Express server listening on port 3000 Dec 15 14:24:33 adminvascosilva volumio[6357]: [Metrics] WebUI: 6s 232.98ms Dec 15 14:24:33 adminvascosilva volumio[6357]: info: CoreStateMachine::resetVolumioState Dec 15 14:24:33 adminvascosilva volumio[6357]: info: CoreStateMachine::getcurrentVolume Dec 15 14:24:33 adminvascosilva volumio[6357]: info: CoreCommandRouter::volumioRetrievevolume Dec 15 14:24:33 adminvascosilva volumio[6357]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:24:33 adminvascosilva volumio[6357]: info: Volumio Network Manager: Network status updated: 1 Dec 15 14:24:33 adminvascosilva volumio-remote-updater[646]: [2025-12-15 14:24:33] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1765808670 101 Dec 15 14:24:33 adminvascosilva volumio[6433]: Forking 3 albumart workers Dec 15 14:24:33 adminvascosilva volumio[6357]: 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:24:33 adminvascosilva volumio[6357]: info: VolumeController:: Volume=25 Mute =false Dec 15 14:24:33 adminvascosilva volumio[6357]: info: CoreStateMachine::pushState Dec 15 14:24:33 adminvascosilva volumio[6357]: info: CorePlayQueue::getTrack 0 Dec 15 14:24:33 adminvascosilva volumio[6357]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 15 14:24:34 adminvascosilva volumio[6357]: info: CoreCommandRouter::volumioPushState Dec 15 14:24:34 adminvascosilva volumio[6357]: info: CoreStateMachine::updateTrackBlock Dec 15 14:24:34 adminvascosilva volumio[6357]: info: CorePlayQueue::getTrackBlock Dec 15 14:24:34 adminvascosilva volumio[6357]: info: CoreCommandRouter::volumioRetrievevolume Dec 15 14:24:34 adminvascosilva volumio[6357]: info: Reloading queue from file Dec 15 14:24:34 adminvascosilva volumio[6357]: info: CoreStateMachine::setRepeat true single undefined Dec 15 14:24:34 adminvascosilva volumio[6357]: info: CoreStateMachine::pushState Dec 15 14:24:34 adminvascosilva volumio[6357]: info: CorePlayQueue::getTrack 0 Dec 15 14:24:34 adminvascosilva volumio[6357]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 15 14:24:34 adminvascosilva volumio[6357]: info: CoreCommandRouter::volumioPushState Dec 15 14:24:34 adminvascosilva volumio[6357]: info: CoreStateMachine::setRandom true Dec 15 14:24:34 adminvascosilva volumio[6357]: info: CoreStateMachine::pushState Dec 15 14:24:34 adminvascosilva volumio[6357]: info: CorePlayQueue::getTrack 0 Dec 15 14:24:34 adminvascosilva volumio[6357]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 15 14:24:34 adminvascosilva volumio[6357]: info: CoreCommandRouter::volumioPushState Dec 15 14:24:34 adminvascosilva volumio[6357]: info: Setting Device type: Raspberry PI Dec 15 14:24:34 adminvascosilva volumio[6357]: info: VolumeController:: Volume=25 Mute =false Dec 15 14:24:34 adminvascosilva volumio[6357]: info: CoreStateMachine::pushState Dec 15 14:24:34 adminvascosilva volumio[6357]: info: CorePlayQueue::getTrack 0 Dec 15 14:24:34 adminvascosilva volumio[6357]: info: CoreCommandRouter::volumioPushState Dec 15 14:24:34 adminvascosilva volumio[6357]: info: Completed loading Core Plugins Dec 15 14:24:34 adminvascosilva volumio[6357]: info: Preparing to generate the ALSA configuration file Dec 15 14:24:34 adminvascosilva volumio[6357]: info: Discovery: adding 5cbf4da9-e3d4-4861-aade-af6465fe6b9d Dec 15 14:24:34 adminvascosilva volumio[6357]: info: Discovery: Found device adminvascosilva Dec 15 14:24:34 adminvascosilva volumio[6357]: info: CoreCommandRouter::volumioGetState Dec 15 14:24:34 adminvascosilva volumio[6357]: info: CorePlayQueue::getTrack 0 Dec 15 14:24:34 adminvascosilva volumio[6357]: info: Discovery: this is already registered, 5cbf4da9-e3d4-4861-aade-af6465fe6b9d Dec 15 14:24:34 adminvascosilva volumio[6357]: info: Discovery: Found device adminvascosilva Dec 15 14:24:34 adminvascosilva volumio[6357]: info: CoreCommandRouter::volumioGetState Dec 15 14:24:34 adminvascosilva volumio[6357]: info: CorePlayQueue::getTrack 0 Dec 15 14:24:34 adminvascosilva volumio[6357]: info: Asound.conf file unchanged, so no further update is needed Dec 15 14:24:34 adminvascosilva volumio[6357]: info: Output device has changed, restarting MPD Dec 15 14:24:34 adminvascosilva volumio[6357]: info: ___________ START PLUGINS ___________ Dec 15 14:24:34 adminvascosilva volumio[6357]: info: ControllerMpd::onStart: Initializing MPD Dec 15 14:24:34 adminvascosilva sudo[6492]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 15 14:24:34 adminvascosilva volumio[6357]: info: Creating MPD Configuration file Dec 15 14:24:34 adminvascosilva sudo[6492]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:24:34 adminvascosilva sudo[6492]: pam_unix(sudo:session): session closed for user root Dec 15 14:24:34 adminvascosilva sudo[6493]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 15 14:24:34 adminvascosilva sudo[6493]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:24:34 adminvascosilva volumio[6357]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 15 14:24:34 adminvascosilva volumio[6357]: info: [1765808674532] CoreMusicLibrary::Adding element Last_100 Dec 15 14:24:34 adminvascosilva volumio[6357]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 14:24:34 adminvascosilva sudo[6498]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 15 14:24:34 adminvascosilva sudo[6498]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:24:34 adminvascosilva volumio[6357]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 15 14:24:34 adminvascosilva volumio[6357]: info: [1765808674559] CoreMusicLibrary::Adding element Webradio Dec 15 14:24:34 adminvascosilva volumio[6357]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 14:24:34 adminvascosilva volumio[6357]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 15 14:24:34 adminvascosilva sudo[6496]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 15 14:24:34 adminvascosilva sudo[6496]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:24:34 adminvascosilva volumio[6357]: info: Initializing BBC Radios Dec 15 14:24:34 adminvascosilva sudo[6496]: pam_unix(sudo:session): session closed for user root Dec 15 14:24:34 adminvascosilva volumio[6357]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 15 14:24:34 adminvascosilva volumio[6357]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:24:34 adminvascosilva volumio[6357]: info: Creating Spotify config file Dec 15 14:24:34 adminvascosilva volumio[6357]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:24:34 adminvascosilva systemd[1]: Starting volumio-keepalive.service - Volumio KeepAlive (start playback if stopped)... Dec 15 14:24:34 adminvascosilva systemd[1]: Stopping mpd.service - Music Player Daemon... Dec 15 14:24:34 adminvascosilva systemd[1]: mpd.service: Deactivated successfully. Dec 15 14:24:34 adminvascosilva systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 15 14:24:34 adminvascosilva systemd[1]: mpd.service: Consumed 3.919s CPU time. Dec 15 14:24:34 adminvascosilva systemd[1]: mpd.socket: Deactivated successfully. Dec 15 14:24:34 adminvascosilva systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 15 14:24:34 adminvascosilva systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 15 14:24:34 adminvascosilva systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 15 14:24:34 adminvascosilva systemd[1]: Starting mpd.service - Music Player Daemon... Dec 15 14:24:35 adminvascosilva sudo[6524]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 15 14:24:35 adminvascosilva sudo[6524]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 15 14:24:35 adminvascosilva sudo[6524]: pam_unix(sudo:session): session closed for user root Dec 15 14:24:35 adminvascosilva volumio[6357]: info: AutoStart - onStart Dec 15 14:24:35 adminvascosilva volumio[6357]: info: Volumio Calling Home Dec 15 14:24:35 adminvascosilva volumio[6357]: info: MPD Permissions set Dec 15 14:24:35 adminvascosilva volumio[6357]: info: MPD Permissions set Dec 15 14:24:35 adminvascosilva volumio[6357]: info: Volumio called home Dec 15 14:24:35 adminvascosilva volumio[6357]: info: Spotify config file written Dec 15 14:24:35 adminvascosilva volumio[6357]: info: CoreCommandRouter::volumioGetState Dec 15 14:24:35 adminvascosilva volumio[6357]: info: CorePlayQueue::getTrack 0 Dec 15 14:24:35 adminvascosilva volumio[6451]: Starting albumart workers Dec 15 14:24:35 adminvascosilva sudo[6531]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Dec 15 14:24:35 adminvascosilva sudo[6531]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:24:36 adminvascosilva systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Dec 15 14:24:36 adminvascosilva systemd[1]: go-librespot-daemon.service: Deactivated successfully. Dec 15 14:24:36 adminvascosilva systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:24:36 adminvascosilva volumio[6450]: Starting albumart workers Dec 15 14:24:36 adminvascosilva volumio[6452]: Starting albumart workers Dec 15 14:24:36 adminvascosilva go-librespot[6535]: go-librespot daemon starting... Dec 15 14:24:36 adminvascosilva systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:24:36 adminvascosilva volumio[6357]: 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:24:36 adminvascosilva sudo[6531]: pam_unix(sudo:session): session closed for user root Dec 15 14:24:36 adminvascosilva volumio[6357]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:24:36 adminvascosilva volumio[6357]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:24:36 adminvascosilva volumio[6357]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:24:36 adminvascosilva volumio[6357]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:24:36 adminvascosilva volumio[6357]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:24:36 adminvascosilva volumio[6357]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:24:36 adminvascosilva volumio[6357]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:24:36 adminvascosilva volumio[6357]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:24:36 adminvascosilva go-librespot[6536]: time="2025-12-15T14:24:36Z" level=info msg="running go-librespot 0.4.0" Dec 15 14:24:36 adminvascosilva go-librespot[6536]: time="2025-12-15T14:24:36Z" level=debug msg="app state loaded" Dec 15 14:24:36 adminvascosilva go-librespot[6536]: time="2025-12-15T14:24:36Z" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 14:24:36 adminvascosilva volumio[6357]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:24:36 adminvascosilva volumio[6357]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:24:36 adminvascosilva volumio[6357]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:24:36 adminvascosilva volumio[6357]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:24:36 adminvascosilva volumio[6357]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:24:36 adminvascosilva volumio[6357]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:24:36 adminvascosilva volumio[6357]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:24:36 adminvascosilva volumio[6357]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:24:36 adminvascosilva volumio[6357]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:24:36 adminvascosilva volumio[6357]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:24:36 adminvascosilva volumio[6357]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:24:36 adminvascosilva volumio[6357]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:24:36 adminvascosilva volumio[6357]: info: No need to fix Spotify hosts Dec 15 14:24:36 adminvascosilva go-librespot[6536]: time="2025-12-15T14:24:36Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 15 14:24:36 adminvascosilva go-librespot[6536]: time="2025-12-15T14:24:36Z" 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:24:36 adminvascosilva go-librespot[6536]: time="2025-12-15T14:24:36Z" 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:24:36 adminvascosilva go-librespot[6536]: time="2025-12-15T14:24:36Z" level=info msg="zeroconf server listening on port 38015" Dec 15 14:24:36 adminvascosilva go-librespot[6536]: time="2025-12-15T14:24:36Z" level=debug msg="obtained new client token: AADgubuqVpL3XnF8X0fEukgX17AOTVeHb0FAfRUH+P+4SqoLY1xE9WLRUHco7UMCQJ8GKU9hHZ/sRcmB5y1OZG7QhTFCnBJpjOefmTimOYULNcbWdTlWXAlTwE0gOCd7+wAKhtAGqtX7m26k8OqCrcb0Q1vmQmDSxOdOh1CrrvQtgH+LT5K/t/GrB6/Kif2KK6J8mM+LMcI/2/Ef7WLwjQDYVnUHvXQ3wMFL5CU1F3UPD4a4rlDqtw==" Dec 15 14:24:36 adminvascosilva go-librespot[6536]: time="2025-12-15T14:24:36Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Dec 15 14:24:36 adminvascosilva go-librespot[6536]: time="2025-12-15T14:24:36Z" level=debug msg="completed keyexchange" Dec 15 14:24:36 adminvascosilva go-librespot[6536]: time="2025-12-15T14:24:36Z" level=debug msg="completed challenge" Dec 15 14:24:36 adminvascosilva volumio[6357]: info: Dec 15 14:24:36 adminvascosilva volumio[6357]: ---------------------------- Client requests Volumio play Dec 15 14:24:36 adminvascosilva volumio[6357]: info: CoreCommandRouter::volumioPlay Dec 15 14:24:36 adminvascosilva volumio[6357]: info: CoreStateMachine::play index undefined Dec 15 14:24:36 adminvascosilva volumio[6357]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 15 14:24:36 adminvascosilva volumio[6357]: info: CorePlayQueue::getTrack 0 Dec 15 14:24:36 adminvascosilva volumio[6357]: info: CoreStateMachine::startPlaybackTimer Dec 15 14:24:36 adminvascosilva volumio[6357]: info: CorePlayQueue::getTrack 0 Dec 15 14:24:36 adminvascosilva volumio[6357]: info: [1765808676938] ControllerSpotify::clearAddPlayTrack Dec 15 14:24:36 adminvascosilva volumio[6357]: info: Sending Spotify command with payload to local API: /player/play Dec 15 14:24:37 adminvascosilva volumio[6357]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 15 14:24:37 adminvascosilva volumio[6357]: SPOTIFY: BQBMH-FVMkwwMn6goNDDxIfAXYSrmMxAKPcLhUM2fgbFTNpVdxjQdDFQFKKWCRIqJZKqGIQWYzxXLcH5f1S2gapSm8OHFlCm0wHkIjTANK7GImCCRBvRQvjwnC0ZFj0j3bwzeQyKgLZtKzgElV5QMZl1pXEQlWwo4Rf_W7wS9XckxrCN8WNscS7-Ciu1urVf9Qo-iyzmS0DCg2cOs3E_b43ooazxmsCQqkrkq6ORyMSLM_QH9f5yUSzOAJa3R7OoEqdEEOVnbUFT4kGxJGNwt0IBpwcp_-3QL-Eocg Dec 15 14:24:37 adminvascosilva volumio[6357]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 15 14:24:37 adminvascosilva volumio[6357]: info: New Spotify access token = BQBMH-FVMkwwMn6goNDDxIfAXYSrmMxAKPcLhUM2fgbFTNpVdxjQdDFQFKKWCRIqJZKqGIQWYzxXLcH5f1S2gapSm8OHFlCm0wHkIjTANK7GImCCRBvRQvjwnC0ZFj0j3bwzeQyKgLZtKzgElV5QMZl1pXEQlWwo4Rf_W7wS9XckxrCN8WNscS7-Ciu1urVf9Qo-iyzmS0DCg2cOs3E_b43ooazxmsCQqkrkq6ORyMSLM_QH9f5yUSzOAJa3R7OoEqdEEOVnbUFT4kGxJGNwt0IBpwcp_-3QL-Eocg Dec 15 14:24:37 adminvascosilva systemd[1]: volumio-keepalive.service: Deactivated successfully. Dec 15 14:24:37 adminvascosilva volumio[6357]: info: Spotify credentials grant success - running version from March 24, 2019 Dec 15 14:24:37 adminvascosilva systemd[1]: Finished volumio-keepalive.service - Volumio KeepAlive (start playback if stopped). Dec 15 14:24:37 adminvascosilva volumio[6357]: info: CoreCommandRouter::volumioGetState Dec 15 14:24:37 adminvascosilva volumio[6357]: info: CorePlayQueue::getTrack 0 Dec 15 14:24:37 adminvascosilva volumio[6357]: 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:24:37 adminvascosilva volumio[6357]: info: Spotify Successfully logged in Dec 15 14:24:37 adminvascosilva volumio[6357]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 15 14:24:37 adminvascosilva volumio[6357]: info: [1765808677438] CoreMusicLibrary::Adding element Spotify Dec 15 14:24:37 adminvascosilva volumio[6357]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 14:24:37 adminvascosilva volumio[6357]: Cannot find translation for source Spotify Dec 15 14:24:39 adminvascosilva mpd[6526]: 2025-12-15T14:24:38 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 15 14:24:39 adminvascosilva systemd[1]: Started mpd.service - Music Player Daemon. Dec 15 14:24:39 adminvascosilva sudo[6498]: pam_unix(sudo:session): session closed for user root Dec 15 14:24:39 adminvascosilva sudo[6493]: pam_unix(sudo:session): session closed for user root Dec 15 14:24:39 adminvascosilva volumio[6357]: info: Completed starting Core Plugins Dec 15 14:24:39 adminvascosilva volumio[6357]: info: ------------------------------------------- Dec 15 14:24:39 adminvascosilva volumio[6357]: info: ----- MyVolumio plugins startup ---- Dec 15 14:24:39 adminvascosilva volumio[6357]: info: ------------------------------------------- Dec 15 14:24:39 adminvascosilva volumio[6357]: info: [MyVolumio PluginManager] Fetching plans data.... Dec 15 14:24:39 adminvascosilva volumio[6357]: error: MPD error: The expression evaluated to a falsy value: Dec 15 14:24:39 adminvascosilva volumio[6357]: assert.ok(self.idling) Dec 15 14:24:39 adminvascosilva volumio[6357]: error: The expression evaluated to a falsy value: Dec 15 14:24:39 adminvascosilva volumio[6357]: assert.ok(self.idling) Dec 15 14:24:39 adminvascosilva volumio[6357]: error: updateQueue error: null Dec 15 14:24:39 adminvascosilva volumio[6357]: info: MPD running with PID6526 Dec 15 14:24:39 adminvascosilva volumio[6357]: ,establishing connection Dec 15 14:24:39 adminvascosilva volumio[6357]: error: updateQueue error: null Dec 15 14:24:39 adminvascosilva volumio[6357]: info: go-librespot daemon successfully initialized Dec 15 14:24:40 adminvascosilva sudo[6593]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 15 14:24:40 adminvascosilva sudo[6593]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:24:40 adminvascosilva sudo[6595]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 15 14:24:40 adminvascosilva sudo[6593]: pam_unix(sudo:session): session closed for user root Dec 15 14:24:40 adminvascosilva sudo[6595]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:24:40 adminvascosilva sudo[6595]: pam_unix(sudo:session): session closed for user root Dec 15 14:24:40 adminvascosilva sudo[6599]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Dec 15 14:24:40 adminvascosilva sudo[6599]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:24:40 adminvascosilva sudo[6599]: pam_unix(sudo:session): session closed for user root Dec 15 14:24:40 adminvascosilva volumio[6357]: info: Upmpdcli Daemon Started Dec 15 14:24:42 adminvascosilva sudo[6604]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 15 14:24:42 adminvascosilva sudo[6604]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:24:42 adminvascosilva sudo[6606]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 15 14:24:42 adminvascosilva sudo[6606]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:24:42 adminvascosilva systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Dec 15 14:24:42 adminvascosilva systemd[1]: mpd_monitor.service: Deactivated successfully. Dec 15 14:24:42 adminvascosilva systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Dec 15 14:24:42 adminvascosilva systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Dec 15 14:24:42 adminvascosilva sudo[6604]: pam_unix(sudo:session): session closed for user root Dec 15 14:24:42 adminvascosilva mpd_monitor.sh[6609]: MPD Monitor Service: Starting MPD Monitor Service Dec 15 14:24:42 adminvascosilva volumio[6357]: info: Successfully started MPD Monitor Dec 15 14:24:42 adminvascosilva sudo[6606]: pam_unix(sudo:session): session closed for user root Dec 15 14:24:42 adminvascosilva volumio[6357]: info: Successfully started MPD Monitor Dec 15 14:24:42 adminvascosilva volumio[6357]: info: Initializing connection to go-librespot Websocket Dec 15 14:24:42 adminvascosilva go-librespot[6536]: time="2025-12-15T14:24:42Z" level=debug msg="new websocket client" Dec 15 14:24:42 adminvascosilva volumio[6357]: info: Connection to go-librespot Websocket established Dec 15 14:24:43 adminvascosilva go-librespot[6536]: time="2025-12-15T14:24:43Z" level=info msg="authenticated AP" username="ha*******ds" Dec 15 14:24:44 adminvascosilva volumio[6357]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Dec 15 14:24:45 adminvascosilva volumio[6357]: info: Getting Spotify volume Dec 15 14:24:45 adminvascosilva volumio[6357]: 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:24:45 adminvascosilva volumio[6357]: info: CoreCommandRouter::volumioGetState Dec 15 14:24:45 adminvascosilva volumio[6357]: info: CorePlayQueue::getTrack 0 Dec 15 14:24:45 adminvascosilva volumio[6357]: SPOTIFY: RECEIVED VOLUMIO VOLUME 25 Dec 15 14:24:45 adminvascosilva volumio[6357]: SPOTIFY: SPOTIFY VOLUME undefined Dec 15 14:24:45 adminvascosilva volumio[6357]: SPOTIFY: VOLUMIO VOLUME 25 Dec 15 14:24:45 adminvascosilva volumio[6357]: info: Aligning Spotify Volume to Volumio Volume Dec 15 14:24:45 adminvascosilva volumio[6357]: info: CoreCommandRouter::volumioGetState Dec 15 14:24:45 adminvascosilva volumio[6357]: info: CorePlayQueue::getTrack 0 Dec 15 14:24:45 adminvascosilva volumio[6357]: info: Setting Spotify Volume from Volumio: 25 Dec 15 14:24:47 adminvascosilva volumio[6357]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Dec 15 14:24:47 adminvascosilva volumio[6357]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Dec 15 14:24:47 adminvascosilva volumio[6357]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Dec 15 14:24:47 adminvascosilva volumio[6357]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Dec 15 14:24:47 adminvascosilva volumio[6357]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Dec 15 14:24:47 adminvascosilva volumio[6357]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Dec 15 14:24:47 adminvascosilva volumio[6357]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Dec 15 14:24:47 adminvascosilva volumio[6357]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Dec 15 14:24:47 adminvascosilva volumio[6357]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Dec 15 14:24:47 adminvascosilva volumio[6357]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Dec 15 14:24:47 adminvascosilva volumio[6357]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Dec 15 14:24:47 adminvascosilva volumio[6357]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Dec 15 14:24:47 adminvascosilva volumio[6357]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Dec 15 14:24:47 adminvascosilva volumio[6357]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Dec 15 14:24:47 adminvascosilva volumio[6357]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Dec 15 14:24:47 adminvascosilva volumio[6357]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Dec 15 14:24:47 adminvascosilva volumio[6357]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Dec 15 14:24:47 adminvascosilva volumio[6357]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Dec 15 14:24:47 adminvascosilva volumio[6357]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Dec 15 14:24:47 adminvascosilva volumio[6357]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Dec 15 14:24:47 adminvascosilva volumio[6357]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Dec 15 14:24:47 adminvascosilva volumio[6357]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Dec 15 14:24:47 adminvascosilva volumio[6357]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Dec 15 14:24:47 adminvascosilva volumio[6357]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Dec 15 14:24:47 adminvascosilva volumio[6357]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Dec 15 14:24:47 adminvascosilva volumio[6357]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Dec 15 14:24:47 adminvascosilva volumio[6357]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Dec 15 14:24:47 adminvascosilva volumio[6357]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Dec 15 14:24:47 adminvascosilva volumio[6357]: info: Adding plugin bluetooth to MyMusic Plugins Dec 15 14:24:47 adminvascosilva volumio[6357]: info: Adding plugin multiroom to MyMusic Plugins Dec 15 14:24:47 adminvascosilva volumio[6357]: info: Adding plugin metavolumio to MyMusic Plugins Dec 15 14:24:47 adminvascosilva volumio[6357]: info: Adding plugin cd_controller to MyMusic Plugins Dec 15 14:24:47 adminvascosilva volumio[6357]: info: Adding plugin qobuzconnect to MyMusic Plugins Dec 15 14:24:47 adminvascosilva volumio[6357]: info: Adding plugin smart_inputs to MyMusic Plugins Dec 15 14:24:47 adminvascosilva volumio[6357]: info: Adding plugin tidalconnect to MyMusic Plugins Dec 15 14:24:47 adminvascosilva volumio[6357]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Dec 15 14:24:48 adminvascosilva volumio[6357]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Dec 15 14:24:48 adminvascosilva volumio[6357]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Dec 15 14:24:48 adminvascosilva volumio[6357]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:24:48 adminvascosilva volumio[6357]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:24:48 adminvascosilva volumio[6357]: info: Starting MyVolumio Remote Streaming Endpoints Dec 15 14:24:48 adminvascosilva volumio[6357]: info: MyVolumio login type: Token Dec 15 14:24:48 adminvascosilva volumio[6357]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Dec 15 14:24:48 adminvascosilva volumio[6357]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Dec 15 14:24:49 adminvascosilva volumio[6357]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Dec 15 14:24:49 adminvascosilva volumio[6357]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Dec 15 14:24:49 adminvascosilva volumio[6357]: info: Streaming services startup Dec 15 14:24:49 adminvascosilva volumio[6357]: info: Starting Streaming Daemon Dec 15 14:24:49 adminvascosilva sudo[6617]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Dec 15 14:24:49 adminvascosilva sudo[6617]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:24:49 adminvascosilva volumio[6357]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Dec 15 14:24:49 adminvascosilva sudo[6617]: pam_unix(sudo:session): session closed for user root Dec 15 14:24:49 adminvascosilva volumio[6357]: SPOTIFY: SETTING SPOTIFY VOLUME 25 Dec 15 14:24:49 adminvascosilva volumio[6357]: info: Sending Spotify command with payload to local API: /player/volume Dec 15 14:24:49 adminvascosilva volumio[6357]: error: Cannot start Volumio Streaming Daemon Dec 15 14:24:49 adminvascosilva volumio[6357]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Dec 15 14:24:49 adminvascosilva volumio[6357]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Dec 15 14:24:49 adminvascosilva volumio[6357]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Dec 15 14:24:50 adminvascosilva volumio[6357]: info: MyVolumio token set successfully Dec 15 14:24:50 adminvascosilva volumio[6357]: info: MYVOLUMIO: Adding device Dec 15 14:24:50 adminvascosilva volumio[6357]: info: MYVOLUMIO: Evaluating Server Dec 15 14:24:50 adminvascosilva volumio[6357]: info: MyVolumio status changed Dec 15 14:24:50 adminvascosilva volumio[6357]: info: Streaming services startup Dec 15 14:24:50 adminvascosilva volumio[6357]: info: Starting Streaming Daemon Dec 15 14:24:50 adminvascosilva volumio[6357]: info: Removing browser output: myVolumio user plan is not superstar Dec 15 14:24:50 adminvascosilva volumio[6357]: info: Removing audio output: Dec 15 14:24:50 adminvascosilva volumio[6357]: info: Stoppping Tunnel 1 Dec 15 14:24:50 adminvascosilva sudo[6659]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Dec 15 14:24:50 adminvascosilva sudo[6659]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:24:50 adminvascosilva sudo[6661]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Dec 15 14:24:50 adminvascosilva sudo[6661]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:24:50 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:24:50 adminvascosilva sudo[6659]: pam_unix(sudo:session): session closed for user root Dec 15 14:24:50 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:24:50 adminvascosilva volumio[6357]: error: Cannot start Volumio Streaming Daemon Dec 15 14:24:50 adminvascosilva volumio[6357]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Dec 15 14:24:50 adminvascosilva volumio[6357]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Dec 15 14:24:50 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:24:50 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:24:50 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:24:50 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:24:50 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:24:50 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:24:50 adminvascosilva sudo[6661]: pam_unix(sudo:session): session closed for user root Dec 15 14:24:50 adminvascosilva volumio[6357]: info: Remote SSH Stopped Dec 15 14:24:50 adminvascosilva volumio[6357]: info: Setting Geolocation for MyVolumio to eu3 Dec 15 14:24:50 adminvascosilva volumio[6357]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:24:50 adminvascosilva volumio[6357]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:24:50 adminvascosilva volumio[6357]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:24:50 adminvascosilva volumio[6357]: info: Successfully Added MyVolumio device Dec 15 14:24:51 adminvascosilva volumio[6357]: info: Updating MyVolumio device info Dec 15 14:24:51 adminvascosilva volumio[6357]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:24:51 adminvascosilva volumio[6357]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:24:51 adminvascosilva volumio[6357]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:24:52 adminvascosilva volumio[6357]: info: Successfully Updated MyVolumio device Dec 15 14:24:52 adminvascosilva go-librespot[6536]: time="2025-12-15T14:24:52Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: UNKNOWN_ERROR" Dec 15 14:24:52 adminvascosilva systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 14:24:52 adminvascosilva systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 14:24:52 adminvascosilva volumio[6357]: error: Failed to send command to Spotify local API: /player/volume: Error: socket hang up Dec 15 14:24:52 adminvascosilva volumio[6357]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 15 14:24:52 adminvascosilva volumio[6357]: Error: socket hang up Dec 15 14:24:52 adminvascosilva volumio[6357]: at connResetException (node:internal/errors:720:14) Dec 15 14:24:52 adminvascosilva volumio[6357]: at Socket.socketOnEnd (node:_http_client:519:23) Dec 15 14:24:52 adminvascosilva volumio[6357]: at Socket.emit (node:events:526:35) Dec 15 14:24:52 adminvascosilva volumio[6357]: at endReadableNT (node:internal/streams/readable:1376:12) Dec 15 14:24:52 adminvascosilva volumio[6357]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Dec 15 14:24:52 adminvascosilva volumio[6357]: code: 'ECONNRESET', Dec 15 14:24:52 adminvascosilva volumio[6357]: response: undefined Dec 15 14:24:52 adminvascosilva volumio[6357]: } Dec 15 14:24:52 adminvascosilva volumio[6357]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 15 14:24:53 adminvascosilva sudo[6678]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-15 14:23' Dec 15 14:24:53 adminvascosilva sudo[6678]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:24:53 adminvascosilva sudo[6678]: pam_unix(sudo:session): session closed for user root Dec 15 14:24:53 adminvascosilva volumio-remote-updater[646]: [2025-12-15 14:24:53] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Dec 15 14:24:53 adminvascosilva volumio-remote-updater[646]: [2025-12-15 14:24:53] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Dec 15 14:24:53 adminvascosilva systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Dec 15 14:24:54 adminvascosilva systemd[1]: volumio.service: Failed with result 'exit-code'. Dec 15 14:24:54 adminvascosilva systemd[1]: volumio.service: Consumed 26.228s CPU time. Dec 15 14:24:54 adminvascosilva systemd[1]: Started dynamicswap.service - dynamicswap service. Dec 15 14:24:54 adminvascosilva systemd[1]: dynamicswap.service: Deactivated successfully. Dec 15 14:24:54 adminvascosilva systemd[1]: volumio.service: Scheduled restart job, restart counter is at 15. Dec 15 14:24:54 adminvascosilva systemd[1]: Started dynamicswap.service - dynamicswap service. Dec 15 14:24:54 adminvascosilva systemd[1]: Stopped volumio.service - Volumio Backend Module. Dec 15 14:24:54 adminvascosilva systemd[1]: volumio.service: Consumed 26.228s CPU time. Dec 15 14:24:54 adminvascosilva systemd[1]: Started volumio.service - Volumio Backend Module. Dec 15 14:24:54 adminvascosilva systemd[1]: dynamicswap.service: Deactivated successfully. Dec 15 14:24:56 adminvascosilva systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Dec 15 14:24:56 adminvascosilva systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:24:56 adminvascosilva systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:24:56 adminvascosilva go-librespot[6706]: go-librespot daemon starting... Dec 15 14:24:56 adminvascosilva go-librespot[6707]: time="2025-12-15T14:24:56Z" level=info msg="running go-librespot 0.4.0" Dec 15 14:24:56 adminvascosilva go-librespot[6707]: time="2025-12-15T14:24:56Z" level=debug msg="app state loaded" Dec 15 14:24:56 adminvascosilva go-librespot[6707]: time="2025-12-15T14:24:56Z" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 14:24:56 adminvascosilva volumio[6691]: info: ------------------------------------------- Dec 15 14:24:56 adminvascosilva volumio[6691]: info: ----- Volumio3 ---- Dec 15 14:24:56 adminvascosilva volumio[6691]: info: ------------------------------------------- Dec 15 14:24:56 adminvascosilva volumio[6691]: info: ----- System startup ---- Dec 15 14:24:56 adminvascosilva volumio[6691]: info: ------------------------------------------- Dec 15 14:24:56 adminvascosilva go-librespot[6707]: time="2025-12-15T14:24:56Z" 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:24:56 adminvascosilva go-librespot[6707]: time="2025-12-15T14:24:56Z" 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:24:56 adminvascosilva go-librespot[6707]: time="2025-12-15T14:24:56Z" 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:24:56 adminvascosilva go-librespot[6707]: time="2025-12-15T14:24:56Z" level=info msg="zeroconf server listening on port 45131" Dec 15 14:24:56 adminvascosilva go-librespot[6707]: time="2025-12-15T14:24:56Z" level=debug msg="obtained new client token: AAAsdP89tHmtzWM/9VFtxg6HI9DQcT749a3Xf75igqX1ARydYSkDxKVLGcAl1M2aVAxsVXsXzstLAV+gRC6Aypx/Vi4WAknWlcZk9UrE4t7DogCByCUV4sinFUtcfZIrcp/nX9vTJSr0s81KFiemv/hqd1nsJ99GgtjS0EA2qMAWRBXKS9KPZ1IutJfixMV7fKGDOdo6ItWxDvTU10qv56A7vLw5pC3zpSZjKrvsdubCkYWvgaCy0Q==" Dec 15 14:24:56 adminvascosilva go-librespot[6707]: time="2025-12-15T14:24:56Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Dec 15 14:24:56 adminvascosilva go-librespot[6707]: time="2025-12-15T14:24:56Z" level=debug msg="completed keyexchange" Dec 15 14:24:56 adminvascosilva go-librespot[6707]: time="2025-12-15T14:24:56Z" level=debug msg="completed challenge" Dec 15 14:24:56 adminvascosilva go-librespot[6707]: time="2025-12-15T14:24:56Z" level=info msg="authenticated AP" username="ha*******ds" Dec 15 14:24:57 adminvascosilva go-librespot[6707]: time="2025-12-15T14:24:57Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating with login5: failed authenticating with login5: UNKNOWN_ERROR" Dec 15 14:24:57 adminvascosilva systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 14:24:57 adminvascosilva systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 14:24:57 adminvascosilva volumio[6691]: info: MYVOLUMIO Environment detected Dec 15 14:24:57 adminvascosilva volumio[6691]: info: Plugin folders cleanup Dec 15 14:24:57 adminvascosilva volumio[6691]: info: Scanning into folder /volumio/app/plugins/ Dec 15 14:24:57 adminvascosilva volumio[6691]: info: Scanning category audio_interface Dec 15 14:24:57 adminvascosilva volumio[6691]: info: Scanning category miscellanea Dec 15 14:24:57 adminvascosilva volumio[6691]: info: Scanning category music_service Dec 15 14:24:57 adminvascosilva volumio[6691]: info: Scanning category plugins.json Dec 15 14:24:57 adminvascosilva volumio[6691]: info: Scanning category system_controller Dec 15 14:24:57 adminvascosilva volumio[6691]: info: Scanning category user_interface Dec 15 14:24:57 adminvascosilva volumio[6691]: info: Scanning into folder /data/plugins/ Dec 15 14:24:57 adminvascosilva volumio[6691]: info: Scanning category music_service Dec 15 14:24:57 adminvascosilva volumio[6691]: info: Scanning category system_controller Dec 15 14:24:57 adminvascosilva volumio[6691]: info: Plugin folders cleanup completed Dec 15 14:24:57 adminvascosilva volumio[6691]: info: ------------------------------------------- Dec 15 14:24:57 adminvascosilva volumio[6691]: info: ----- Core plugins startup ---- Dec 15 14:24:57 adminvascosilva volumio[6691]: info: ------------------------------------------- Dec 15 14:24:57 adminvascosilva volumio[6691]: info: Loading plugins from folder /volumio/app/plugins/ Dec 15 14:24:57 adminvascosilva volumio[6691]: info: Adding plugin upnp to MyMusic Plugins Dec 15 14:24:57 adminvascosilva volumio[6691]: info: Adding plugin airplay_emulation to MyMusic Plugins Dec 15 14:24:57 adminvascosilva volumio[6691]: info: Adding plugin upnp_browser to MyMusic Plugins Dec 15 14:24:57 adminvascosilva volumio[6691]: info: Loading plugins from folder /data/plugins/ Dec 15 14:24:57 adminvascosilva volumio[6691]: info: Loading plugin "system"... Dec 15 14:24:57 adminvascosilva volumio[6691]: info: Loading plugin "appearance"... Dec 15 14:24:58 adminvascosilva volumio[6691]: info: Loading plugin "network"... Dec 15 14:24:58 adminvascosilva volumio[6691]: info: Refreshing Cached IP Addresses Dec 15 14:24:58 adminvascosilva sudo[6729]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 15 14:24:58 adminvascosilva sudo[6729]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:24:58 adminvascosilva volumio[6691]: info: Loading plugin "services"... Dec 15 14:24:58 adminvascosilva sudo[6731]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 15 14:24:58 adminvascosilva sudo[6731]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:24:58 adminvascosilva volumio[6691]: info: Loading plugin "alsa_controller"... Dec 15 14:24:58 adminvascosilva sudo[6729]: pam_unix(sudo:session): session closed for user root Dec 15 14:24:58 adminvascosilva sudo[6731]: pam_unix(sudo:session): session closed for user root Dec 15 14:24:58 adminvascosilva volumio[6691]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 15 14:24:58 adminvascosilva volumio[6691]: info: Loading plugin "wizard"... Dec 15 14:24:58 adminvascosilva volumio[6691]: info: Loading plugin "networkfs"... Dec 15 14:24:58 adminvascosilva volumio[6691]: info: Starting Udev Watcher for removable devices Dec 15 14:24:58 adminvascosilva volumio[6691]: info: Ignoring mount for partition: boot Dec 15 14:24:58 adminvascosilva volumio[6691]: info: Ignoring mount for partition: volumio Dec 15 14:24:58 adminvascosilva volumio[6691]: info: Ignoring mount for partition: volumio_data Dec 15 14:24:58 adminvascosilva volumio[6691]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 15 14:24:58 adminvascosilva volumio[6691]: info: Loading plugin "volumio_command_line_client"... Dec 15 14:24:58 adminvascosilva volumio[6691]: info: Loading plugin "upnp"... Dec 15 14:24:58 adminvascosilva volumio[6691]: info: [1765808698517] Starting Upmpd Daemon Dec 15 14:24:58 adminvascosilva volumio[6691]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 15 14:24:58 adminvascosilva volumio[6691]: info: Loading plugin "my_music"... Dec 15 14:24:58 adminvascosilva volumio[6691]: info: Loading plugin "mpd"... Dec 15 14:24:58 adminvascosilva volumio[6691]: info: Plugin upnp_browser is not enabled Dec 15 14:24:58 adminvascosilva volumio[6691]: info: Loading plugin "alarm-clock"... Dec 15 14:24:58 adminvascosilva volumio-remote-updater[646]: [2025-12-15 14:24:58] [connect] Successful connection Dec 15 14:24:59 adminvascosilva volumio[6691]: info: Plugin airplay_emulation is not enabled Dec 15 14:24:59 adminvascosilva volumio[6691]: info: Loading plugin "last_100"... Dec 15 14:24:59 adminvascosilva volumio[6691]: info: Loading plugin "webradio"... Dec 15 14:25:00 adminvascosilva systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Dec 15 14:25:00 adminvascosilva systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:25:00 adminvascosilva systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:25:00 adminvascosilva go-librespot[6759]: go-librespot daemon starting... Dec 15 14:25:00 adminvascosilva go-librespot[6760]: time="2025-12-15T14:25:00Z" level=info msg="running go-librespot 0.4.0" Dec 15 14:25:00 adminvascosilva go-librespot[6760]: time="2025-12-15T14:25:00Z" level=debug msg="app state loaded" Dec 15 14:25:00 adminvascosilva go-librespot[6760]: time="2025-12-15T14:25:00Z" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 14:25:00 adminvascosilva volumio[6691]: info: Loading plugin "i2s_dacs"... Dec 15 14:25:00 adminvascosilva volumio[6691]: info: I2S DAC not set, start Auto-detection Dec 15 14:25:00 adminvascosilva volumio[6691]: info: Loading plugin "volumiodiscovery"... Dec 15 14:25:00 adminvascosilva volumio[6691]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 15 14:25:00 adminvascosilva volumio[6691]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 15 14:25:00 adminvascosilva volumio[6691]: *** WARNING *** For more information see Dec 15 14:25:00 adminvascosilva volumio[6691]: *** 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:25:00 adminvascosilva volumio[6691]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 15 14:25:00 adminvascosilva volumio[6691]: *** WARNING *** For more information see Dec 15 14:25:00 adminvascosilva node[6691]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 15 14:25:00 adminvascosilva node[6691]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 15 14:25:00 adminvascosilva node[6691]: *** WARNING *** For more information see Dec 15 14:25:00 adminvascosilva node[6691]: *** 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:25:00 adminvascosilva node[6691]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 15 14:25:00 adminvascosilva node[6691]: *** WARNING *** For more information see Dec 15 14:25:00 adminvascosilva volumio[6691]: info: Applying required configuration parameters for plugin volumiodiscovery Dec 15 14:25:00 adminvascosilva volumio[6691]: info: Discovery: Started advertising with name: adminvascosilva Dec 15 14:25:00 adminvascosilva volumio[6691]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 15 14:25:00 adminvascosilva volumio[6691]: info: Loading plugin "spop"... Dec 15 14:25:00 adminvascosilva go-librespot[6760]: time="2025-12-15T14:25:00Z" 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:25:00 adminvascosilva go-librespot[6760]: time="2025-12-15T14:25:00Z" 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:25:00 adminvascosilva go-librespot[6760]: time="2025-12-15T14:25:00Z" 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:25:00 adminvascosilva go-librespot[6760]: time="2025-12-15T14:25:00Z" level=info msg="zeroconf server listening on port 35095" Dec 15 14:25:00 adminvascosilva go-librespot[6760]: time="2025-12-15T14:25:00Z" level=debug msg="obtained new client token: AADQiRUiCITb/JINrxrida3stuEeKYTMrn6IjFxoK0Wo3wy4zdWQ65TCZOywxj3fymRQxgMGbf6OIfU6z/hy05YHNeGWqiRcDQEUbIBvCReoxFQ4L56mOOGXpNsAr5sxFoRh6/bOOWcLO8QQsathGsKBgB0PkESC4+bZbaOScMCvAogBvSADRqjbYefvY0XZbP/oYnJVoAL7qO/D1HdaAvVMo3Ps67u1NtDbZO6tQERnPNEWHwAHGQ==" Dec 15 14:25:00 adminvascosilva go-librespot[6760]: time="2025-12-15T14:25:00Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Dec 15 14:25:00 adminvascosilva go-librespot[6760]: time="2025-12-15T14:25:00Z" level=debug msg="completed keyexchange" Dec 15 14:25:00 adminvascosilva go-librespot[6760]: time="2025-12-15T14:25:00Z" level=debug msg="completed challenge" Dec 15 14:25:01 adminvascosilva volumio[6691]: info: Loading plugin "autostart"... Dec 15 14:25:01 adminvascosilva volumio[6691]: info: Applying required configuration parameters for plugin autostart Dec 15 14:25:01 adminvascosilva volumio[6691]: info: AutoStart - onVolumioStart - read config.json Dec 15 14:25:01 adminvascosilva volumio[6691]: info: Loading plugin "outputs"... Dec 15 14:25:01 adminvascosilva volumio[6691]: info: Loading plugin "albumart"... Dec 15 14:25:01 adminvascosilva volumio[6691]: info: Plugin example_plugin is not enabled Dec 15 14:25:01 adminvascosilva volumio[6691]: info: Loading plugin "inputs"... Dec 15 14:25:01 adminvascosilva volumio[6691]: info: Loading plugin "updater_comm"... Dec 15 14:25:01 adminvascosilva volumio[6691]: info: Plugin mpdemulation is not enabled Dec 15 14:25:01 adminvascosilva volumio[6691]: info: Loading plugin "rest_api"... Dec 15 14:25:01 adminvascosilva volumio[6691]: info: Loading plugin "websocket"... Dec 15 14:25:01 adminvascosilva volumio[6691]: info: Starting Socket.io Server version 1.7.4 Dec 15 14:25:01 adminvascosilva volumio[6691]: info: Loading i18n strings for locale pt Dec 15 14:25:01 adminvascosilva volumio[6691]: Updating browse sources language Dec 15 14:25:01 adminvascosilva volumio[6691]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 14:25:01 adminvascosilva volumio[6691]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 15 14:25:02 adminvascosilva volumio[6691]: info: CoreCommandRouter::initPlayerControls Dec 15 14:25:02 adminvascosilva volumio[6691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:25:02 adminvascosilva volumio[6691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:25:02 adminvascosilva volumio[6691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:25:02 adminvascosilva volumio[6691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:25:02 adminvascosilva volumio[6691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:25:02 adminvascosilva volumio[6691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:25:02 adminvascosilva volumio[6691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:25:02 adminvascosilva volumio[6691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:25:02 adminvascosilva volumio[6691]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 15 14:25:02 adminvascosilva volumio[6691]: Express server listening on port 3000 Dec 15 14:25:02 adminvascosilva volumio[6691]: [Metrics] WebUI: 6s 205.54ms Dec 15 14:25:02 adminvascosilva volumio[6691]: info: CoreStateMachine::resetVolumioState Dec 15 14:25:02 adminvascosilva volumio[6691]: info: CoreStateMachine::getcurrentVolume Dec 15 14:25:02 adminvascosilva volumio[6691]: info: CoreCommandRouter::volumioRetrievevolume Dec 15 14:25:02 adminvascosilva volumio[6691]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:25:02 adminvascosilva volumio[6691]: info: Volumio Network Manager: Network status updated: 1 Dec 15 14:25:02 adminvascosilva volumio-remote-updater[646]: [2025-12-15 14:25:02] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1765808698 101 Dec 15 14:25:02 adminvascosilva volumio[6770]: Forking 3 albumart workers Dec 15 14:25:02 adminvascosilva volumio[6691]: 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:25:02 adminvascosilva volumio[6691]: info: VolumeController:: Volume=25 Mute =false Dec 15 14:25:02 adminvascosilva volumio[6691]: info: CoreStateMachine::pushState Dec 15 14:25:02 adminvascosilva volumio[6691]: info: CorePlayQueue::getTrack 0 Dec 15 14:25:02 adminvascosilva volumio[6691]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 15 14:25:02 adminvascosilva volumio[6691]: info: CoreCommandRouter::volumioPushState Dec 15 14:25:02 adminvascosilva volumio[6691]: info: CoreStateMachine::updateTrackBlock Dec 15 14:25:02 adminvascosilva volumio[6691]: info: CorePlayQueue::getTrackBlock Dec 15 14:25:02 adminvascosilva volumio[6691]: info: CoreCommandRouter::volumioRetrievevolume Dec 15 14:25:02 adminvascosilva volumio[6691]: info: Reloading queue from file Dec 15 14:25:02 adminvascosilva volumio[6691]: info: CoreStateMachine::setRepeat true single undefined Dec 15 14:25:02 adminvascosilva volumio[6691]: info: CoreStateMachine::pushState Dec 15 14:25:02 adminvascosilva volumio[6691]: info: CorePlayQueue::getTrack 0 Dec 15 14:25:02 adminvascosilva volumio[6691]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 15 14:25:02 adminvascosilva volumio[6691]: info: CoreCommandRouter::volumioPushState Dec 15 14:25:02 adminvascosilva volumio[6691]: info: CoreStateMachine::setRandom true Dec 15 14:25:02 adminvascosilva volumio[6691]: info: CoreStateMachine::pushState Dec 15 14:25:02 adminvascosilva volumio[6691]: info: CorePlayQueue::getTrack 0 Dec 15 14:25:02 adminvascosilva volumio[6691]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 15 14:25:02 adminvascosilva volumio[6691]: info: CoreCommandRouter::volumioPushState Dec 15 14:25:02 adminvascosilva volumio[6691]: info: Setting Device type: Raspberry PI Dec 15 14:25:02 adminvascosilva volumio[6691]: info: VolumeController:: Volume=25 Mute =false Dec 15 14:25:02 adminvascosilva volumio[6691]: info: CoreStateMachine::pushState Dec 15 14:25:02 adminvascosilva volumio[6691]: info: CorePlayQueue::getTrack 0 Dec 15 14:25:02 adminvascosilva volumio[6691]: info: CoreCommandRouter::volumioPushState Dec 15 14:25:02 adminvascosilva volumio[6691]: info: Completed loading Core Plugins Dec 15 14:25:02 adminvascosilva volumio[6691]: info: Preparing to generate the ALSA configuration file Dec 15 14:25:02 adminvascosilva volumio[6691]: info: Discovery: adding 5cbf4da9-e3d4-4861-aade-af6465fe6b9d Dec 15 14:25:02 adminvascosilva volumio[6691]: info: Discovery: Found device adminvascosilva Dec 15 14:25:02 adminvascosilva volumio[6691]: info: CoreCommandRouter::volumioGetState Dec 15 14:25:02 adminvascosilva volumio[6691]: info: CorePlayQueue::getTrack 0 Dec 15 14:25:02 adminvascosilva volumio[6691]: info: Discovery: this is already registered, 5cbf4da9-e3d4-4861-aade-af6465fe6b9d Dec 15 14:25:02 adminvascosilva volumio[6691]: info: Discovery: Found device adminvascosilva Dec 15 14:25:02 adminvascosilva volumio[6691]: info: CoreCommandRouter::volumioGetState Dec 15 14:25:02 adminvascosilva volumio[6691]: info: CorePlayQueue::getTrack 0 Dec 15 14:25:02 adminvascosilva volumio[6691]: info: Asound.conf file unchanged, so no further update is needed Dec 15 14:25:02 adminvascosilva volumio[6691]: info: Output device has changed, restarting MPD Dec 15 14:25:02 adminvascosilva volumio[6691]: info: ___________ START PLUGINS ___________ Dec 15 14:25:02 adminvascosilva volumio[6691]: info: ControllerMpd::onStart: Initializing MPD Dec 15 14:25:02 adminvascosilva volumio[6691]: info: Creating MPD Configuration file Dec 15 14:25:02 adminvascosilva sudo[6831]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 15 14:25:02 adminvascosilva sudo[6831]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:25:02 adminvascosilva sudo[6830]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 15 14:25:02 adminvascosilva sudo[6830]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:25:02 adminvascosilva sudo[6830]: pam_unix(sudo:session): session closed for user root Dec 15 14:25:02 adminvascosilva volumio[6691]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 15 14:25:02 adminvascosilva volumio[6691]: info: [1765808702846] CoreMusicLibrary::Adding element Last_100 Dec 15 14:25:02 adminvascosilva volumio[6691]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 14:25:02 adminvascosilva volumio[6691]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 15 14:25:02 adminvascosilva volumio[6691]: info: [1765808702855] CoreMusicLibrary::Adding element Webradio Dec 15 14:25:02 adminvascosilva volumio[6691]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 14:25:02 adminvascosilva sudo[6834]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 15 14:25:02 adminvascosilva volumio[6691]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 15 14:25:02 adminvascosilva sudo[6834]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:25:02 adminvascosilva volumio[6691]: info: Initializing BBC Radios Dec 15 14:25:02 adminvascosilva systemd[1]: Stopping mpd.service - Music Player Daemon... Dec 15 14:25:02 adminvascosilva sudo[6834]: pam_unix(sudo:session): session closed for user root Dec 15 14:25:02 adminvascosilva sudo[6837]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 15 14:25:02 adminvascosilva sudo[6837]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:25:02 adminvascosilva systemd[1]: mpd.service: Deactivated successfully. Dec 15 14:25:02 adminvascosilva systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 15 14:25:02 adminvascosilva systemd[1]: mpd.service: Consumed 3.909s CPU time. Dec 15 14:25:02 adminvascosilva systemd[1]: mpd.socket: Deactivated successfully. Dec 15 14:25:02 adminvascosilva systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 15 14:25:02 adminvascosilva systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 15 14:25:03 adminvascosilva volumio[6691]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 15 14:25:03 adminvascosilva volumio[6691]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:25:03 adminvascosilva systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 15 14:25:03 adminvascosilva systemd[1]: Starting mpd.service - Music Player Daemon... Dec 15 14:25:03 adminvascosilva volumio[6691]: info: Creating Spotify config file Dec 15 14:25:03 adminvascosilva systemd[1]: mpd.service: Deactivated successfully. Dec 15 14:25:03 adminvascosilva systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 15 14:25:03 adminvascosilva volumio[6691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:25:03 adminvascosilva systemd[1]: mpd.socket: Deactivated successfully. Dec 15 14:25:03 adminvascosilva systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 15 14:25:03 adminvascosilva systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 15 14:25:03 adminvascosilva systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 15 14:25:03 adminvascosilva systemd[1]: Starting mpd.service - Music Player Daemon... Dec 15 14:25:03 adminvascosilva sudo[6857]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 15 14:25:03 adminvascosilva sudo[6857]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 15 14:25:03 adminvascosilva sudo[6857]: pam_unix(sudo:session): session closed for user root Dec 15 14:25:03 adminvascosilva volumio[6691]: info: AutoStart - onStart Dec 15 14:25:03 adminvascosilva volumio[6691]: info: Volumio Calling Home Dec 15 14:25:03 adminvascosilva volumio[6789]: Starting albumart workers Dec 15 14:25:03 adminvascosilva volumio[6691]: info: MPD Permissions set Dec 15 14:25:04 adminvascosilva volumio[6691]: info: MPD Permissions set Dec 15 14:25:04 adminvascosilva volumio[6691]: info: Volumio called home Dec 15 14:25:04 adminvascosilva volumio[6691]: info: Spotify config file written Dec 15 14:25:04 adminvascosilva volumio[6691]: 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:25:04 adminvascosilva volumio[6691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:25:04 adminvascosilva volumio[6691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:25:04 adminvascosilva volumio[6691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:25:04 adminvascosilva volumio[6691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:25:04 adminvascosilva volumio[6691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:25:04 adminvascosilva volumio[6691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:25:04 adminvascosilva sudo[6864]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Dec 15 14:25:04 adminvascosilva volumio[6691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:25:04 adminvascosilva sudo[6864]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:25:04 adminvascosilva volumio[6691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:25:04 adminvascosilva volumio[6691]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:25:04 adminvascosilva volumio[6691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:25:04 adminvascosilva volumio[6691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:25:04 adminvascosilva systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Dec 15 14:25:04 adminvascosilva volumio[6691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:25:04 adminvascosilva systemd[1]: go-librespot-daemon.service: Deactivated successfully. Dec 15 14:25:04 adminvascosilva volumio[6691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:25:04 adminvascosilva systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:25:04 adminvascosilva volumio[6691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:25:04 adminvascosilva volumio[6691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:25:04 adminvascosilva volumio[6691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:25:04 adminvascosilva volumio[6691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:25:04 adminvascosilva volumio[6691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:25:04 adminvascosilva volumio[6691]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:25:04 adminvascosilva volumio[6691]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:25:04 adminvascosilva volumio[6691]: info: No need to fix Spotify hosts Dec 15 14:25:04 adminvascosilva volumio[6785]: Starting albumart workers Dec 15 14:25:04 adminvascosilva systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:25:04 adminvascosilva go-librespot[6871]: go-librespot daemon starting... Dec 15 14:25:04 adminvascosilva sudo[6864]: pam_unix(sudo:session): session closed for user root Dec 15 14:25:04 adminvascosilva go-librespot[6877]: time="2025-12-15T14:25:04Z" level=info msg="running go-librespot 0.4.0" Dec 15 14:25:04 adminvascosilva go-librespot[6877]: time="2025-12-15T14:25:04Z" level=debug msg="app state loaded" Dec 15 14:25:04 adminvascosilva go-librespot[6877]: time="2025-12-15T14:25:04Z" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 14:25:04 adminvascosilva volumio[6787]: Starting albumart workers Dec 15 14:25:04 adminvascosilva volumio[6691]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 15 14:25:04 adminvascosilva volumio[6691]: SPOTIFY: BQC69oLSRgtLdNaLHwuHTPENXurWIcT3YAmfRbnPJrmFDQxdHhd_dGd0rbn8J6ic5bXmkTX9hOr8MIIHkEBZcNENvXrCE5hyaeZma7K5ibymP4-UITNN4N9XpomTz-b1nGoYMTntEx0-vqnnjG6a2XSOtQfkrZMavlhIPOrTatuSdbrxzjuB7h91Bv8xIYcappXmr0Xjv8BnXdNLy58l80L3yzLqOi0Ck27Ca9TIWJs_1Co2kUkNn7Ta6o1VudUJRYksOgColUYPl50qq7vQGfBESn6wbALSHw6qQw Dec 15 14:25:04 adminvascosilva volumio[6691]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 15 14:25:04 adminvascosilva volumio[6691]: info: New Spotify access token = BQC69oLSRgtLdNaLHwuHTPENXurWIcT3YAmfRbnPJrmFDQxdHhd_dGd0rbn8J6ic5bXmkTX9hOr8MIIHkEBZcNENvXrCE5hyaeZma7K5ibymP4-UITNN4N9XpomTz-b1nGoYMTntEx0-vqnnjG6a2XSOtQfkrZMavlhIPOrTatuSdbrxzjuB7h91Bv8xIYcappXmr0Xjv8BnXdNLy58l80L3yzLqOi0Ck27Ca9TIWJs_1Co2kUkNn7Ta6o1VudUJRYksOgColUYPl50qq7vQGfBESn6wbALSHw6qQw Dec 15 14:25:04 adminvascosilva volumio[6691]: info: Spotify credentials grant success - running version from March 24, 2019 Dec 15 14:25:04 adminvascosilva go-librespot[6877]: time="2025-12-15T14:25: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-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Dec 15 14:25:04 adminvascosilva go-librespot[6877]: time="2025-12-15T14:25:04Z" 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:25:04 adminvascosilva go-librespot[6877]: time="2025-12-15T14:25:04Z" 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:25:04 adminvascosilva go-librespot[6877]: time="2025-12-15T14:25:04Z" level=info msg="zeroconf server listening on port 41653" Dec 15 14:25:04 adminvascosilva go-librespot[6877]: time="2025-12-15T14:25:04Z" level=debug msg="obtained new client token: AAAS8phjUcwwxx5OWRS3NWazzydb6wjGHp8Y4PSlLEsO8gAlR9wjNE8fmBlE5bFS0YDc4/qhZ+dE+4s3JXNf9a0KcfXRNUip7gk0qjmuOXvaQ7SAsGcpHfRVHhen0YDFYixPInFNDpO8y9xWfTmzS+Ikcg+khyxO+VmWlZeoPktNiM9U24w4EbsNGo/FO1Ik0Tm/U8+qfpl8Nt52xf1P3VV36SS5Nz+lfdoT9Qt9L3qVgy7FiQMBcQ==" Dec 15 14:25:04 adminvascosilva volumio[6691]: info: CoreCommandRouter::volumioGetState Dec 15 14:25:04 adminvascosilva volumio[6691]: info: CorePlayQueue::getTrack 0 Dec 15 14:25:04 adminvascosilva go-librespot[6877]: time="2025-12-15T14:25:04Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Dec 15 14:25:04 adminvascosilva go-librespot[6877]: time="2025-12-15T14:25:04Z" level=debug msg="completed keyexchange" Dec 15 14:25:04 adminvascosilva go-librespot[6877]: time="2025-12-15T14:25:04Z" level=debug msg="completed challenge" Dec 15 14:25:04 adminvascosilva go-librespot[6877]: time="2025-12-15T14:25:04Z" 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:25:04 adminvascosilva systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 14:25:04 adminvascosilva systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 14:25:05 adminvascosilva volumio[6691]: 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:25:05 adminvascosilva volumio[6691]: info: Spotify Successfully logged in Dec 15 14:25:05 adminvascosilva volumio[6691]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 15 14:25:05 adminvascosilva volumio[6691]: info: [1765808705068] CoreMusicLibrary::Adding element Spotify Dec 15 14:25:05 adminvascosilva volumio[6691]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 14:25:05 adminvascosilva volumio[6691]: Cannot find translation for source Spotify Dec 15 14:25:07 adminvascosilva mpd[6859]: 2025-12-15T14:25:07 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 15 14:25:07 adminvascosilva systemd[1]: Started mpd.service - Music Player Daemon. Dec 15 14:25:07 adminvascosilva sudo[6831]: pam_unix(sudo:session): session closed for user root Dec 15 14:25:07 adminvascosilva sudo[6837]: pam_unix(sudo:session): session closed for user root Dec 15 14:25:07 adminvascosilva volumio[6691]: info: Completed starting Core Plugins Dec 15 14:25:07 adminvascosilva volumio[6691]: info: ------------------------------------------- Dec 15 14:25:07 adminvascosilva volumio[6691]: info: ----- MyVolumio plugins startup ---- Dec 15 14:25:07 adminvascosilva volumio[6691]: info: ------------------------------------------- Dec 15 14:25:07 adminvascosilva volumio[6691]: info: [MyVolumio PluginManager] Fetching plans data.... Dec 15 14:25:07 adminvascosilva volumio[6691]: error: MPD error: The expression evaluated to a falsy value: Dec 15 14:25:07 adminvascosilva volumio[6691]: assert.ok(self.idling) Dec 15 14:25:07 adminvascosilva volumio[6691]: error: The expression evaluated to a falsy value: Dec 15 14:25:07 adminvascosilva volumio[6691]: assert.ok(self.idling) Dec 15 14:25:07 adminvascosilva volumio[6691]: error: updateQueue error: null Dec 15 14:25:07 adminvascosilva volumio[6691]: info: MPD running with PID6859 Dec 15 14:25:07 adminvascosilva volumio[6691]: ,establishing connection Dec 15 14:25:07 adminvascosilva volumio[6691]: error: updateQueue error: null Dec 15 14:25:07 adminvascosilva volumio[6691]: info: go-librespot daemon successfully initialized Dec 15 14:25:08 adminvascosilva systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Dec 15 14:25:08 adminvascosilva systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:25:08 adminvascosilva systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:25:08 adminvascosilva go-librespot[6909]: go-librespot daemon starting... Dec 15 14:25:08 adminvascosilva go-librespot[6910]: time="2025-12-15T14:25:08Z" level=info msg="running go-librespot 0.4.0" Dec 15 14:25:08 adminvascosilva go-librespot[6910]: time="2025-12-15T14:25:08Z" level=debug msg="app state loaded" Dec 15 14:25:08 adminvascosilva go-librespot[6910]: time="2025-12-15T14:25:08Z" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 14:25:08 adminvascosilva go-librespot[6910]: time="2025-12-15T14:25:08Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Dec 15 14:25:08 adminvascosilva go-librespot[6910]: time="2025-12-15T14:25:08Z" 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:25:08 adminvascosilva go-librespot[6910]: time="2025-12-15T14:25:08Z" 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:25:08 adminvascosilva go-librespot[6910]: time="2025-12-15T14:25:08Z" level=info msg="zeroconf server listening on port 33251" Dec 15 14:25:08 adminvascosilva go-librespot[6910]: time="2025-12-15T14:25:08Z" level=debug msg="obtained new client token: AAD6DX1W9uInXuj6LxWpqxSZ46sHIX8axCxhEhJtWWOXgmhyDEu8ttEylunobdvMGcAWHYSrTLI3BMgdtNPsm5iNx2Te3AH7raKDhb+RyIFw8U1u8iIoOTwlmm66DpowSpBMVyYfYdqu74lSRY3CD2VLq4SHNiTxjvzfz/GNfGr87j3JRAsq3biM9QPRim8ZB5pgmb3e/17Qo0H69X82MGTNUvsdL1y/w+xCjYRRIIHBahNi2DIBSg==" Dec 15 14:25:08 adminvascosilva go-librespot[6910]: time="2025-12-15T14:25:08Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Dec 15 14:25:08 adminvascosilva sudo[6932]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 15 14:25:08 adminvascosilva sudo[6932]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:25:08 adminvascosilva sudo[6932]: pam_unix(sudo:session): session closed for user root Dec 15 14:25:08 adminvascosilva sudo[6934]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 15 14:25:08 adminvascosilva sudo[6934]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:25:08 adminvascosilva sudo[6934]: pam_unix(sudo:session): session closed for user root Dec 15 14:25:08 adminvascosilva go-librespot[6910]: time="2025-12-15T14:25:08Z" level=debug msg="completed keyexchange" Dec 15 14:25:08 adminvascosilva go-librespot[6910]: time="2025-12-15T14:25:08Z" level=debug msg="completed challenge" Dec 15 14:25:08 adminvascosilva sudo[6938]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Dec 15 14:25:08 adminvascosilva sudo[6938]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:25:08 adminvascosilva sudo[6938]: pam_unix(sudo:session): session closed for user root Dec 15 14:25:08 adminvascosilva volumio[6691]: info: Upmpdcli Daemon Started Dec 15 14:25:08 adminvascosilva go-librespot[6910]: time="2025-12-15T14:25: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:25:08 adminvascosilva systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 14:25:08 adminvascosilva systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 14:25:10 adminvascosilva sudo[6943]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 15 14:25:10 adminvascosilva sudo[6943]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:25:10 adminvascosilva sudo[6945]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 15 14:25:10 adminvascosilva sudo[6945]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:25:10 adminvascosilva systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Dec 15 14:25:10 adminvascosilva systemd[1]: mpd_monitor.service: Deactivated successfully. Dec 15 14:25:10 adminvascosilva systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Dec 15 14:25:10 adminvascosilva systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Dec 15 14:25:10 adminvascosilva sudo[6943]: pam_unix(sudo:session): session closed for user root Dec 15 14:25:10 adminvascosilva sudo[6945]: pam_unix(sudo:session): session closed for user root Dec 15 14:25:10 adminvascosilva mpd_monitor.sh[6948]: MPD Monitor Service: Starting MPD Monitor Service Dec 15 14:25:10 adminvascosilva volumio[6691]: info: Successfully started MPD Monitor Dec 15 14:25:10 adminvascosilva volumio[6691]: info: Successfully started MPD Monitor Dec 15 14:25:10 adminvascosilva volumio[6691]: info: Initializing connection to go-librespot Websocket Dec 15 14:25:10 adminvascosilva volumio[6691]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 15 14:25:12 adminvascosilva systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Dec 15 14:25:12 adminvascosilva systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:25:12 adminvascosilva systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:25:12 adminvascosilva go-librespot[6954]: go-librespot daemon starting... Dec 15 14:25:12 adminvascosilva go-librespot[6955]: time="2025-12-15T14:25:12Z" level=info msg="running go-librespot 0.4.0" Dec 15 14:25:12 adminvascosilva go-librespot[6955]: time="2025-12-15T14:25:12Z" level=debug msg="app state loaded" Dec 15 14:25:12 adminvascosilva go-librespot[6955]: time="2025-12-15T14:25:12Z" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 14:25:12 adminvascosilva volumio[6691]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Dec 15 14:25:12 adminvascosilva go-librespot[6955]: time="2025-12-15T14:25:12Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew4.spotify.com:443 ap-gae2.spotify.com:80]" Dec 15 14:25:12 adminvascosilva go-librespot[6955]: time="2025-12-15T14:25:12Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew4-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Dec 15 14:25:12 adminvascosilva go-librespot[6955]: time="2025-12-15T14:25:12Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew4-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Dec 15 14:25:12 adminvascosilva go-librespot[6955]: time="2025-12-15T14:25:12Z" level=info msg="zeroconf server listening on port 39233" Dec 15 14:25:12 adminvascosilva go-librespot[6955]: time="2025-12-15T14:25:12Z" level=debug msg="obtained new client token: AAD/bnT38Q27+a1YcjXC3Itvesyvx5PhCHi6ByDeH54JqhKoTW3XCeJNWUvuTVlyYMLE/CJfREk+CQ0cOrgrqpSOU3a8+YdglhWOc6uDOId6ZII1tLhtgoR/FHS6OI+KKJMFD+ieuxepPndroJ40nQHmj2H35Upp19NiHVG88BwUm78U4WfzAvn5AsFbBj9i+X/TOB75eN3TnRS4Jjz8we1XP61OG1by7FP2IsK4stQgPnNqXKX1sw==" Dec 15 14:25:12 adminvascosilva go-librespot[6955]: time="2025-12-15T14:25:12Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Dec 15 14:25:12 adminvascosilva go-librespot[6955]: time="2025-12-15T14:25:12Z" level=debug msg="completed keyexchange" Dec 15 14:25:12 adminvascosilva go-librespot[6955]: time="2025-12-15T14:25:12Z" level=debug msg="completed challenge" Dec 15 14:25:13 adminvascosilva volumio[6691]: info: Initializing connection to go-librespot Websocket Dec 15 14:25:13 adminvascosilva go-librespot[6955]: time="2025-12-15T14:25:13Z" level=debug msg="new websocket client" Dec 15 14:25:13 adminvascosilva volumio[6691]: info: Connection to go-librespot Websocket established Dec 15 14:25:15 adminvascosilva volumio[6691]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Dec 15 14:25:15 adminvascosilva volumio[6691]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Dec 15 14:25:15 adminvascosilva volumio[6691]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Dec 15 14:25:15 adminvascosilva volumio[6691]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Dec 15 14:25:15 adminvascosilva volumio[6691]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Dec 15 14:25:15 adminvascosilva volumio[6691]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Dec 15 14:25:15 adminvascosilva volumio[6691]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Dec 15 14:25:15 adminvascosilva volumio[6691]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Dec 15 14:25:15 adminvascosilva volumio[6691]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Dec 15 14:25:15 adminvascosilva volumio[6691]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Dec 15 14:25:15 adminvascosilva volumio[6691]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Dec 15 14:25:15 adminvascosilva volumio[6691]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Dec 15 14:25:15 adminvascosilva volumio[6691]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Dec 15 14:25:15 adminvascosilva volumio[6691]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Dec 15 14:25:15 adminvascosilva volumio[6691]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Dec 15 14:25:15 adminvascosilva volumio[6691]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Dec 15 14:25:15 adminvascosilva volumio[6691]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Dec 15 14:25:15 adminvascosilva volumio[6691]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Dec 15 14:25:15 adminvascosilva volumio[6691]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Dec 15 14:25:15 adminvascosilva volumio[6691]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Dec 15 14:25:15 adminvascosilva volumio[6691]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Dec 15 14:25:15 adminvascosilva volumio[6691]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Dec 15 14:25:15 adminvascosilva volumio[6691]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Dec 15 14:25:15 adminvascosilva volumio[6691]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Dec 15 14:25:15 adminvascosilva volumio[6691]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Dec 15 14:25:15 adminvascosilva volumio[6691]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Dec 15 14:25:15 adminvascosilva volumio[6691]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Dec 15 14:25:15 adminvascosilva volumio[6691]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Dec 15 14:25:15 adminvascosilva volumio[6691]: info: Adding plugin bluetooth to MyMusic Plugins Dec 15 14:25:15 adminvascosilva volumio[6691]: info: Adding plugin multiroom to MyMusic Plugins Dec 15 14:25:15 adminvascosilva volumio[6691]: info: Adding plugin metavolumio to MyMusic Plugins Dec 15 14:25:15 adminvascosilva volumio[6691]: info: Adding plugin cd_controller to MyMusic Plugins Dec 15 14:25:15 adminvascosilva volumio[6691]: info: Adding plugin qobuzconnect to MyMusic Plugins Dec 15 14:25:15 adminvascosilva volumio[6691]: info: Adding plugin smart_inputs to MyMusic Plugins Dec 15 14:25:15 adminvascosilva volumio[6691]: info: Adding plugin tidalconnect to MyMusic Plugins Dec 15 14:25:15 adminvascosilva volumio[6691]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Dec 15 14:25:16 adminvascosilva volumio[6691]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Dec 15 14:25:16 adminvascosilva volumio[6691]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Dec 15 14:25:16 adminvascosilva volumio[6691]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:25:16 adminvascosilva volumio[6691]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:25:16 adminvascosilva volumio[6691]: info: Starting MyVolumio Remote Streaming Endpoints Dec 15 14:25:16 adminvascosilva volumio[6691]: info: MyVolumio login type: Token Dec 15 14:25:16 adminvascosilva volumio[6691]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Dec 15 14:25:16 adminvascosilva volumio[6691]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Dec 15 14:25:17 adminvascosilva volumio[6691]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Dec 15 14:25:17 adminvascosilva volumio[6691]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Dec 15 14:25:17 adminvascosilva volumio[6691]: info: Streaming services startup Dec 15 14:25:17 adminvascosilva volumio[6691]: info: Starting Streaming Daemon Dec 15 14:25:17 adminvascosilva sudo[6964]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Dec 15 14:25:17 adminvascosilva sudo[6964]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:25:17 adminvascosilva volumio[6691]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Dec 15 14:25:17 adminvascosilva sudo[6964]: pam_unix(sudo:session): session closed for user root Dec 15 14:25:17 adminvascosilva volumio[6691]: info: Getting Spotify volume Dec 15 14:25:17 adminvascosilva volumio[6691]: error: Cannot start Volumio Streaming Daemon Dec 15 14:25:17 adminvascosilva volumio[6691]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Dec 15 14:25:17 adminvascosilva volumio[6691]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Dec 15 14:25:17 adminvascosilva volumio[6691]: 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:25:17 adminvascosilva go-librespot[6955]: time="2025-12-15T14:25:17Z" 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:25:17 adminvascosilva systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 14:25:17 adminvascosilva systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 14:25:17 adminvascosilva volumio[6691]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 15 14:25:17 adminvascosilva volumio[6691]: Error: socket hang up Dec 15 14:25:17 adminvascosilva volumio[6691]: at connResetException (node:internal/errors:720:14) Dec 15 14:25:17 adminvascosilva volumio[6691]: at Socket.socketOnEnd (node:_http_client:519:23) Dec 15 14:25:17 adminvascosilva volumio[6691]: at Socket.emit (node:events:526:35) Dec 15 14:25:17 adminvascosilva volumio[6691]: at endReadableNT (node:internal/streams/readable:1376:12) Dec 15 14:25:17 adminvascosilva volumio[6691]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Dec 15 14:25:17 adminvascosilva volumio[6691]: code: 'ECONNRESET', Dec 15 14:25:17 adminvascosilva volumio[6691]: response: undefined Dec 15 14:25:17 adminvascosilva volumio[6691]: } Dec 15 14:25:17 adminvascosilva volumio[6691]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 15 14:25:18 adminvascosilva sudo[6985]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-15 14:24' Dec 15 14:25:18 adminvascosilva sudo[6985]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:25:18 adminvascosilva sudo[6985]: pam_unix(sudo:session): session closed for user root Dec 15 14:25:18 adminvascosilva volumio-remote-updater[646]: [2025-12-15 14:25:18] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Dec 15 14:25:18 adminvascosilva volumio-remote-updater[646]: [2025-12-15 14:25:18] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Dec 15 14:25:18 adminvascosilva systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Dec 15 14:25:18 adminvascosilva systemd[1]: volumio.service: Failed with result 'exit-code'. Dec 15 14:25:18 adminvascosilva systemd[1]: volumio.service: Consumed 24.826s CPU time. Dec 15 14:25:18 adminvascosilva systemd[1]: Started dynamicswap.service - dynamicswap service. Dec 15 14:25:18 adminvascosilva systemd[1]: dynamicswap.service: Deactivated successfully. Dec 15 14:25:18 adminvascosilva systemd[1]: volumio.service: Scheduled restart job, restart counter is at 16. Dec 15 14:25:18 adminvascosilva systemd[1]: Started dynamicswap.service - dynamicswap service. Dec 15 14:25:18 adminvascosilva systemd[1]: Stopped volumio.service - Volumio Backend Module. Dec 15 14:25:18 adminvascosilva systemd[1]: volumio.service: Consumed 24.826s CPU time. Dec 15 14:25:18 adminvascosilva systemd[1]: Started volumio.service - Volumio Backend Module. Dec 15 14:25:18 adminvascosilva systemd[1]: dynamicswap.service: Deactivated successfully. Dec 15 14:25:20 adminvascosilva systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Dec 15 14:25:20 adminvascosilva systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:25:20 adminvascosilva systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:25:20 adminvascosilva go-librespot[7027]: go-librespot daemon starting... Dec 15 14:25:20 adminvascosilva go-librespot[7033]: time="2025-12-15T14:25:20Z" level=info msg="running go-librespot 0.4.0" Dec 15 14:25:20 adminvascosilva go-librespot[7033]: time="2025-12-15T14:25:20Z" level=debug msg="app state loaded" Dec 15 14:25:20 adminvascosilva go-librespot[7033]: time="2025-12-15T14:25:20Z" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 14:25:20 adminvascosilva volumio[7012]: info: ------------------------------------------- Dec 15 14:25:20 adminvascosilva volumio[7012]: info: ----- Volumio3 ---- Dec 15 14:25:20 adminvascosilva volumio[7012]: info: ------------------------------------------- Dec 15 14:25:20 adminvascosilva volumio[7012]: info: ----- System startup ---- Dec 15 14:25:20 adminvascosilva volumio[7012]: info: ------------------------------------------- Dec 15 14:25:20 adminvascosilva go-librespot[7033]: time="2025-12-15T14:25:20Z" 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:25:20 adminvascosilva go-librespot[7033]: time="2025-12-15T14:25:20Z" 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:25:20 adminvascosilva go-librespot[7033]: time="2025-12-15T14:25:20Z" 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:25:20 adminvascosilva go-librespot[7033]: time="2025-12-15T14:25:20Z" level=info msg="zeroconf server listening on port 41387" Dec 15 14:25:21 adminvascosilva go-librespot[7033]: time="2025-12-15T14:25:21Z" level=debug msg="obtained new client token: AAD9IFKCXLad7P78L7ia2w32kxsZx7f7slxshGrH+N2KMz/gzhM9BwQz/ITFOlbpZxgIw0gV5Z5rxQyRChCUBaTUvj5EjA80K+tJZX4XGuzzJ8OVspgu0TnnN8wbpUq7JblXajl8IBjFawQ7tv6MVAOB94fyIOnngF1n3Q+RpE3GUtUenKh3OstlgTrz0HvdXIuTxPObrZ5hrL66qC/HuQBFrhUUxJlcRxyLA39VVbDaMJlNxQA=" Dec 15 14:25:21 adminvascosilva go-librespot[7033]: time="2025-12-15T14:25:21Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Dec 15 14:25:21 adminvascosilva go-librespot[7033]: time="2025-12-15T14:25:21Z" level=debug msg="completed keyexchange" Dec 15 14:25:21 adminvascosilva go-librespot[7033]: time="2025-12-15T14:25:21Z" level=debug msg="completed challenge" Dec 15 14:25:21 adminvascosilva go-librespot[7033]: time="2025-12-15T14:25:21Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TryAnotherAP " Dec 15 14:25:21 adminvascosilva systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 14:25:21 adminvascosilva systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 14:25:21 adminvascosilva volumio[7012]: info: MYVOLUMIO Environment detected Dec 15 14:25:21 adminvascosilva volumio[7012]: info: Plugin folders cleanup Dec 15 14:25:21 adminvascosilva volumio[7012]: info: Scanning into folder /volumio/app/plugins/ Dec 15 14:25:21 adminvascosilva volumio[7012]: info: Scanning category audio_interface Dec 15 14:25:21 adminvascosilva volumio[7012]: info: Scanning category miscellanea Dec 15 14:25:21 adminvascosilva volumio[7012]: info: Scanning category music_service Dec 15 14:25:21 adminvascosilva volumio[7012]: info: Scanning category plugins.json Dec 15 14:25:21 adminvascosilva volumio[7012]: info: Scanning category system_controller Dec 15 14:25:21 adminvascosilva volumio[7012]: info: Scanning category user_interface Dec 15 14:25:21 adminvascosilva volumio[7012]: info: Scanning into folder /data/plugins/ Dec 15 14:25:21 adminvascosilva volumio[7012]: info: Scanning category music_service Dec 15 14:25:21 adminvascosilva volumio[7012]: info: Scanning category system_controller Dec 15 14:25:21 adminvascosilva volumio[7012]: info: Plugin folders cleanup completed Dec 15 14:25:21 adminvascosilva volumio[7012]: info: ------------------------------------------- Dec 15 14:25:21 adminvascosilva volumio[7012]: info: ----- Core plugins startup ---- Dec 15 14:25:21 adminvascosilva volumio[7012]: info: ------------------------------------------- Dec 15 14:25:21 adminvascosilva volumio[7012]: info: Loading plugins from folder /volumio/app/plugins/ Dec 15 14:25:21 adminvascosilva volumio[7012]: info: Adding plugin upnp to MyMusic Plugins Dec 15 14:25:21 adminvascosilva volumio[7012]: info: Adding plugin airplay_emulation to MyMusic Plugins Dec 15 14:25:21 adminvascosilva volumio[7012]: info: Adding plugin upnp_browser to MyMusic Plugins Dec 15 14:25:21 adminvascosilva volumio[7012]: info: Loading plugins from folder /data/plugins/ Dec 15 14:25:21 adminvascosilva volumio[7012]: info: Loading plugin "system"... Dec 15 14:25:21 adminvascosilva volumio[7012]: info: Loading plugin "appearance"... Dec 15 14:25:22 adminvascosilva volumio[7012]: info: Loading plugin "network"... Dec 15 14:25:22 adminvascosilva volumio[7012]: info: Refreshing Cached IP Addresses Dec 15 14:25:22 adminvascosilva sudo[7048]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 15 14:25:22 adminvascosilva volumio[7012]: info: Loading plugin "services"... Dec 15 14:25:22 adminvascosilva sudo[7048]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:25:22 adminvascosilva sudo[7050]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 15 14:25:22 adminvascosilva volumio[7012]: info: Loading plugin "alsa_controller"... Dec 15 14:25:22 adminvascosilva sudo[7050]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:25:22 adminvascosilva sudo[7048]: pam_unix(sudo:session): session closed for user root Dec 15 14:25:22 adminvascosilva sudo[7050]: pam_unix(sudo:session): session closed for user root Dec 15 14:25:22 adminvascosilva volumio[7012]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 15 14:25:22 adminvascosilva volumio[7012]: info: Loading plugin "wizard"... Dec 15 14:25:22 adminvascosilva volumio[7012]: info: Loading plugin "networkfs"... Dec 15 14:25:22 adminvascosilva volumio[7012]: info: Starting Udev Watcher for removable devices Dec 15 14:25:22 adminvascosilva volumio[7012]: info: Ignoring mount for partition: boot Dec 15 14:25:22 adminvascosilva volumio[7012]: info: Ignoring mount for partition: volumio Dec 15 14:25:22 adminvascosilva volumio[7012]: info: Ignoring mount for partition: volumio_data Dec 15 14:25:22 adminvascosilva volumio[7012]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 15 14:25:22 adminvascosilva volumio[7012]: info: Loading plugin "volumio_command_line_client"... Dec 15 14:25:22 adminvascosilva volumio[7012]: info: Loading plugin "upnp"... Dec 15 14:25:22 adminvascosilva volumio[7012]: info: [1765808722956] Starting Upmpd Daemon Dec 15 14:25:22 adminvascosilva volumio[7012]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 15 14:25:22 adminvascosilva volumio[7012]: info: Loading plugin "my_music"... Dec 15 14:25:22 adminvascosilva volumio[7012]: info: Loading plugin "mpd"... Dec 15 14:25:23 adminvascosilva volumio[7012]: info: Plugin upnp_browser is not enabled Dec 15 14:25:23 adminvascosilva volumio[7012]: info: Loading plugin "alarm-clock"... Dec 15 14:25:23 adminvascosilva volumio[7012]: info: Plugin airplay_emulation is not enabled Dec 15 14:25:23 adminvascosilva volumio[7012]: info: Loading plugin "last_100"... Dec 15 14:25:23 adminvascosilva volumio[7012]: info: Loading plugin "webradio"... Dec 15 14:25:23 adminvascosilva volumio-remote-updater[646]: [2025-12-15 14:25:23] [connect] Successful connection Dec 15 14:25:24 adminvascosilva systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Dec 15 14:25:24 adminvascosilva systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:25:24 adminvascosilva systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:25:24 adminvascosilva go-librespot[7078]: go-librespot daemon starting... Dec 15 14:25:24 adminvascosilva go-librespot[7079]: time="2025-12-15T14:25:24Z" level=info msg="running go-librespot 0.4.0" Dec 15 14:25:24 adminvascosilva go-librespot[7079]: time="2025-12-15T14:25:24Z" level=debug msg="app state loaded" Dec 15 14:25:24 adminvascosilva go-librespot[7079]: time="2025-12-15T14:25:24Z" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 14:25:24 adminvascosilva go-librespot[7079]: time="2025-12-15T14:25: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-gae2.spotify.com:80]" Dec 15 14:25:24 adminvascosilva go-librespot[7079]: time="2025-12-15T14:25:24Z" 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:25:24 adminvascosilva go-librespot[7079]: time="2025-12-15T14:25:24Z" 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:25:24 adminvascosilva go-librespot[7079]: time="2025-12-15T14:25:24Z" level=info msg="zeroconf server listening on port 43623" Dec 15 14:25:24 adminvascosilva volumio[7012]: info: Loading plugin "i2s_dacs"... Dec 15 14:25:24 adminvascosilva volumio[7012]: info: I2S DAC not set, start Auto-detection Dec 15 14:25:24 adminvascosilva volumio[7012]: info: Loading plugin "volumiodiscovery"... Dec 15 14:25:24 adminvascosilva go-librespot[7079]: time="2025-12-15T14:25:24Z" level=debug msg="obtained new client token: AADcEFTxJXJ7Dfk45Uoi2KBl/r9V4XkAGAB+9mFnPkTYoUK9k2s7E93Hnp3G7qHpfPp4cs6/gSmiTA+Ucst2zPfISL9ltbAtDSneivv6zEvAwQASOo6bp4L9haytn/e1jR7brI9txnmGAjBoQS3OsoSmL0LqlqUTAwdFOz5n31DhTjXW45f/e6Rk1oGgzABanz79vMdWGyZVek1lvtoIV0kH0DfaC1EfuZPboBx/+vqTl7cX0sG+fA==" Dec 15 14:25:24 adminvascosilva volumio[7012]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 15 14:25:24 adminvascosilva volumio[7012]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 15 14:25:24 adminvascosilva volumio[7012]: *** WARNING *** For more information see Dec 15 14:25:24 adminvascosilva volumio[7012]: *** 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:25:24 adminvascosilva volumio[7012]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 15 14:25:24 adminvascosilva volumio[7012]: *** WARNING *** For more information see Dec 15 14:25:24 adminvascosilva node[7012]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Dec 15 14:25:24 adminvascosilva node[7012]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 15 14:25:24 adminvascosilva node[7012]: *** WARNING *** For more information see Dec 15 14:25:24 adminvascosilva node[7012]: *** 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:25:24 adminvascosilva node[7012]: *** WARNING *** Please fix your application to use the native API of Avahi! Dec 15 14:25:24 adminvascosilva node[7012]: *** WARNING *** For more information see Dec 15 14:25:24 adminvascosilva volumio[7012]: info: Applying required configuration parameters for plugin volumiodiscovery Dec 15 14:25:24 adminvascosilva volumio[7012]: info: Discovery: Started advertising with name: adminvascosilva Dec 15 14:25:24 adminvascosilva go-librespot[7079]: time="2025-12-15T14:25:24Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Dec 15 14:25:24 adminvascosilva volumio[7012]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Dec 15 14:25:24 adminvascosilva volumio[7012]: info: Loading plugin "spop"... Dec 15 14:25:24 adminvascosilva go-librespot[7079]: time="2025-12-15T14:25:24Z" level=debug msg="completed keyexchange" Dec 15 14:25:24 adminvascosilva go-librespot[7079]: time="2025-12-15T14:25:24Z" level=debug msg="completed challenge" Dec 15 14:25:24 adminvascosilva go-librespot[7079]: time="2025-12-15T14:25: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:25:24 adminvascosilva systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 14:25:24 adminvascosilva systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 14:25:25 adminvascosilva volumio[7012]: info: Loading plugin "autostart"... Dec 15 14:25:26 adminvascosilva volumio[7012]: info: Applying required configuration parameters for plugin autostart Dec 15 14:25:26 adminvascosilva volumio[7012]: info: AutoStart - onVolumioStart - read config.json Dec 15 14:25:26 adminvascosilva volumio[7012]: info: Loading plugin "outputs"... Dec 15 14:25:26 adminvascosilva volumio[7012]: info: Loading plugin "albumart"... Dec 15 14:25:26 adminvascosilva volumio[7012]: info: Plugin example_plugin is not enabled Dec 15 14:25:26 adminvascosilva volumio[7012]: info: Loading plugin "inputs"... Dec 15 14:25:26 adminvascosilva volumio[7012]: info: Loading plugin "updater_comm"... Dec 15 14:25:26 adminvascosilva volumio[7012]: info: Plugin mpdemulation is not enabled Dec 15 14:25:26 adminvascosilva volumio[7012]: info: Loading plugin "rest_api"... Dec 15 14:25:26 adminvascosilva volumio[7012]: info: Loading plugin "websocket"... Dec 15 14:25:26 adminvascosilva volumio[7012]: info: Starting Socket.io Server version 1.7.4 Dec 15 14:25:26 adminvascosilva volumio[7012]: info: Loading i18n strings for locale pt Dec 15 14:25:26 adminvascosilva volumio[7012]: Updating browse sources language Dec 15 14:25:26 adminvascosilva volumio[7012]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 14:25:26 adminvascosilva volumio[7012]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 15 14:25:26 adminvascosilva volumio[7012]: info: CoreCommandRouter::initPlayerControls Dec 15 14:25:26 adminvascosilva volumio[7012]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:25:26 adminvascosilva volumio[7012]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:25:26 adminvascosilva volumio[7012]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:25:26 adminvascosilva volumio[7012]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:25:26 adminvascosilva volumio[7012]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:25:26 adminvascosilva volumio[7012]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:25:26 adminvascosilva volumio[7012]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:25:26 adminvascosilva volumio[7012]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:25:26 adminvascosilva volumio[7012]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Dec 15 14:25:26 adminvascosilva volumio[7012]: Express server listening on port 3000 Dec 15 14:25:26 adminvascosilva volumio[7012]: [Metrics] WebUI: 6s 192.73ms Dec 15 14:25:26 adminvascosilva volumio[7012]: info: CoreStateMachine::resetVolumioState Dec 15 14:25:26 adminvascosilva volumio[7012]: info: CoreStateMachine::getcurrentVolume Dec 15 14:25:26 adminvascosilva volumio[7012]: info: CoreCommandRouter::volumioRetrievevolume Dec 15 14:25:26 adminvascosilva volumio[7012]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:25:26 adminvascosilva volumio[7012]: info: Volumio Network Manager: Network status updated: 1 Dec 15 14:25:26 adminvascosilva volumio-remote-updater[646]: [2025-12-15 14:25:26] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1765808723 101 Dec 15 14:25:26 adminvascosilva volumio[7088]: Forking 3 albumart workers Dec 15 14:25:26 adminvascosilva volumio[7012]: 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:25:26 adminvascosilva volumio[7012]: info: VolumeController:: Volume=25 Mute =false Dec 15 14:25:26 adminvascosilva volumio[7012]: info: CoreStateMachine::pushState Dec 15 14:25:26 adminvascosilva volumio[7012]: info: CorePlayQueue::getTrack 0 Dec 15 14:25:26 adminvascosilva volumio[7012]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 15 14:25:26 adminvascosilva volumio[7012]: info: CoreCommandRouter::volumioPushState Dec 15 14:25:26 adminvascosilva volumio[7012]: info: CoreStateMachine::updateTrackBlock Dec 15 14:25:26 adminvascosilva volumio[7012]: info: CorePlayQueue::getTrackBlock Dec 15 14:25:26 adminvascosilva volumio[7012]: info: CoreCommandRouter::volumioRetrievevolume Dec 15 14:25:26 adminvascosilva volumio[7012]: info: CoreStateMachine::setRepeat true single undefined Dec 15 14:25:26 adminvascosilva volumio[7012]: info: CoreStateMachine::pushState Dec 15 14:25:26 adminvascosilva volumio[7012]: info: CorePlayQueue::getTrack 0 Dec 15 14:25:26 adminvascosilva volumio[7012]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 15 14:25:26 adminvascosilva volumio[7012]: info: CoreCommandRouter::volumioPushState Dec 15 14:25:26 adminvascosilva volumio[7012]: info: CoreStateMachine::setRandom true Dec 15 14:25:26 adminvascosilva volumio[7012]: info: CoreStateMachine::pushState Dec 15 14:25:26 adminvascosilva volumio[7012]: info: CorePlayQueue::getTrack 0 Dec 15 14:25:26 adminvascosilva volumio[7012]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 15 14:25:26 adminvascosilva volumio[7012]: info: CoreCommandRouter::volumioPushState Dec 15 14:25:26 adminvascosilva volumio[7012]: info: Setting Device type: Raspberry PI Dec 15 14:25:26 adminvascosilva volumio[7012]: info: Reloading queue from file Dec 15 14:25:27 adminvascosilva volumio[7012]: info: VolumeController:: Volume=25 Mute =false Dec 15 14:25:27 adminvascosilva volumio[7012]: info: CoreStateMachine::pushState Dec 15 14:25:27 adminvascosilva volumio[7012]: info: CorePlayQueue::getTrack 0 Dec 15 14:25:27 adminvascosilva volumio[7012]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 15 14:25:27 adminvascosilva volumio[7012]: info: CoreCommandRouter::volumioPushState Dec 15 14:25:27 adminvascosilva volumio[7012]: info: Completed loading Core Plugins Dec 15 14:25:27 adminvascosilva volumio[7012]: info: Preparing to generate the ALSA configuration file Dec 15 14:25:27 adminvascosilva volumio[7012]: info: Discovery: adding 5cbf4da9-e3d4-4861-aade-af6465fe6b9d Dec 15 14:25:27 adminvascosilva volumio[7012]: info: Discovery: Found device adminvascosilva Dec 15 14:25:27 adminvascosilva volumio[7012]: info: CoreCommandRouter::volumioGetState Dec 15 14:25:27 adminvascosilva volumio[7012]: info: CorePlayQueue::getTrack 0 Dec 15 14:25:27 adminvascosilva volumio[7012]: info: Discovery: this is already registered, 5cbf4da9-e3d4-4861-aade-af6465fe6b9d Dec 15 14:25:27 adminvascosilva volumio[7012]: info: Discovery: Found device adminvascosilva Dec 15 14:25:27 adminvascosilva volumio[7012]: info: CoreCommandRouter::volumioGetState Dec 15 14:25:27 adminvascosilva volumio[7012]: info: CorePlayQueue::getTrack 0 Dec 15 14:25:27 adminvascosilva volumio[7012]: info: Asound.conf file unchanged, so no further update is needed Dec 15 14:25:27 adminvascosilva volumio[7012]: info: Output device has changed, restarting MPD Dec 15 14:25:27 adminvascosilva volumio[7012]: info: ___________ START PLUGINS ___________ Dec 15 14:25:27 adminvascosilva volumio[7012]: info: ControllerMpd::onStart: Initializing MPD Dec 15 14:25:27 adminvascosilva volumio[7012]: info: Creating MPD Configuration file Dec 15 14:25:27 adminvascosilva sudo[7147]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 15 14:25:27 adminvascosilva sudo[7147]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:25:27 adminvascosilva sudo[7145]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 15 14:25:27 adminvascosilva sudo[7145]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:25:27 adminvascosilva volumio[7012]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 15 14:25:27 adminvascosilva volumio[7012]: info: [1765808727203] CoreMusicLibrary::Adding element Last_100 Dec 15 14:25:27 adminvascosilva volumio[7012]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 14:25:27 adminvascosilva sudo[7145]: pam_unix(sudo:session): session closed for user root Dec 15 14:25:27 adminvascosilva volumio[7012]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 15 14:25:27 adminvascosilva volumio[7012]: info: [1765808727212] CoreMusicLibrary::Adding element Webradio Dec 15 14:25:27 adminvascosilva volumio[7012]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 14:25:27 adminvascosilva volumio[7012]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 15 14:25:27 adminvascosilva volumio[7012]: info: Initializing BBC Radios Dec 15 14:25:27 adminvascosilva sudo[7149]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Dec 15 14:25:27 adminvascosilva sudo[7149]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:25:27 adminvascosilva systemd[1]: Stopping mpd.service - Music Player Daemon... Dec 15 14:25:27 adminvascosilva sudo[7153]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Dec 15 14:25:27 adminvascosilva sudo[7149]: pam_unix(sudo:session): session closed for user root Dec 15 14:25:27 adminvascosilva sudo[7153]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:25:27 adminvascosilva systemd[1]: mpd.service: Deactivated successfully. Dec 15 14:25:27 adminvascosilva systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 15 14:25:27 adminvascosilva systemd[1]: mpd.service: Consumed 3.930s CPU time. Dec 15 14:25:27 adminvascosilva volumio[7012]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 15 14:25:27 adminvascosilva systemd[1]: mpd.socket: Deactivated successfully. Dec 15 14:25:27 adminvascosilva volumio[7012]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:25:27 adminvascosilva systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 15 14:25:27 adminvascosilva systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 15 14:25:27 adminvascosilva volumio[7012]: info: Creating Spotify config file Dec 15 14:25:27 adminvascosilva volumio[7012]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:25:27 adminvascosilva systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 15 14:25:27 adminvascosilva systemd[1]: Starting mpd.service - Music Player Daemon... Dec 15 14:25:27 adminvascosilva systemd[1]: mpd.service: Deactivated successfully. Dec 15 14:25:27 adminvascosilva systemd[1]: Stopped mpd.service - Music Player Daemon. Dec 15 14:25:27 adminvascosilva systemd[1]: mpd.socket: Deactivated successfully. Dec 15 14:25:27 adminvascosilva systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Dec 15 14:25:27 adminvascosilva systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Dec 15 14:25:27 adminvascosilva systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Dec 15 14:25:27 adminvascosilva systemd[1]: Starting mpd.service - Music Player Daemon... Dec 15 14:25:27 adminvascosilva sudo[7172]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Dec 15 14:25:27 adminvascosilva sudo[7172]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Dec 15 14:25:27 adminvascosilva sudo[7172]: pam_unix(sudo:session): session closed for user root Dec 15 14:25:27 adminvascosilva volumio[7012]: info: AutoStart - onStart Dec 15 14:25:27 adminvascosilva volumio[7012]: info: Volumio Calling Home Dec 15 14:25:28 adminvascosilva systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Dec 15 14:25:28 adminvascosilva systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:25:28 adminvascosilva systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:25:28 adminvascosilva go-librespot[7178]: go-librespot daemon starting... Dec 15 14:25:28 adminvascosilva go-librespot[7181]: time="2025-12-15T14:25:28Z" level=info msg="running go-librespot 0.4.0" Dec 15 14:25:28 adminvascosilva volumio[7012]: info: MPD Permissions set Dec 15 14:25:28 adminvascosilva volumio[7012]: info: MPD Permissions set Dec 15 14:25:28 adminvascosilva volumio[7012]: info: Spotify config file written Dec 15 14:25:28 adminvascosilva sudo[7189]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Dec 15 14:25:28 adminvascosilva sudo[7189]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:25:28 adminvascosilva volumio[7012]: 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:25:28 adminvascosilva volumio[7106]: Starting albumart workers Dec 15 14:25:28 adminvascosilva volumio[7012]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:25:28 adminvascosilva volumio[7012]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:25:28 adminvascosilva volumio[7012]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:25:28 adminvascosilva volumio[7012]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:25:28 adminvascosilva volumio[7012]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:25:28 adminvascosilva volumio[7012]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:25:28 adminvascosilva go-librespot[7181]: time="2025-12-15T14:25:28Z" level=info msg="zeroconf server listening on port 46551" Dec 15 14:25:28 adminvascosilva volumio[7012]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:25:28 adminvascosilva volumio[7012]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:25:28 adminvascosilva volumio[7104]: Starting albumart workers Dec 15 14:25:28 adminvascosilva systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Dec 15 14:25:28 adminvascosilva systemd[1]: go-librespot-daemon.service: Killing process 7187 (go-librespot) with signal SIGKILL. Dec 15 14:25:28 adminvascosilva systemd[1]: go-librespot-daemon.service: Deactivated successfully. Dec 15 14:25:28 adminvascosilva systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:25:28 adminvascosilva volumio[7012]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:25:28 adminvascosilva volumio[7012]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:25:28 adminvascosilva volumio[7012]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:25:28 adminvascosilva volumio[7012]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:25:28 adminvascosilva volumio[7012]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:25:28 adminvascosilva volumio[7012]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:25:28 adminvascosilva volumio[7012]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:25:28 adminvascosilva volumio[7012]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:25:28 adminvascosilva volumio[7012]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:25:28 adminvascosilva volumio[7012]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:25:28 adminvascosilva volumio[7105]: Starting albumart workers Dec 15 14:25:28 adminvascosilva volumio[7012]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:25:28 adminvascosilva volumio[7012]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 15 14:25:28 adminvascosilva volumio[7012]: info: No need to fix Spotify hosts Dec 15 14:25:28 adminvascosilva systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:25:28 adminvascosilva go-librespot[7196]: go-librespot daemon starting... Dec 15 14:25:28 adminvascosilva sudo[7189]: pam_unix(sudo:session): session closed for user root Dec 15 14:25:28 adminvascosilva go-librespot[7202]: time="2025-12-15T14:25:28Z" level=info msg="running go-librespot 0.4.0" Dec 15 14:25:28 adminvascosilva go-librespot[7202]: time="2025-12-15T14:25:28Z" level=debug msg="app state loaded" Dec 15 14:25:28 adminvascosilva go-librespot[7202]: time="2025-12-15T14:25:28Z" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 14:25:29 adminvascosilva volumio[7012]: info: Volumio called home Dec 15 14:25:29 adminvascosilva volumio[7012]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 15 14:25:29 adminvascosilva volumio[7012]: SPOTIFY: BQDlhXB5p7taF156-Y0HY2uOQBNaxF8CJt2Lr9IvOBMH_tsi5YDwh3h48BQq82Vghi3LYDC_LRmtYqGr4BAblIg1c2_WWgkB-PYBosBtWA5B3p9ArkEK0IlczHQ3R_0a4_VaYpOz6Rn3O_YhnDPHL94AyjWBCxlUtibVwWtQP8KFwYtAaCsDj0R4bYrQcQkKAWBaRnWIY5ExzBAz04KNDJFOxNqELrK_mbyDxDOL5XU6FfIApB5RmkBHFkrRpa4BXPf6PzV63Pu7ueMb7FKcvIMoroOLmyTpYw2L2A Dec 15 14:25:29 adminvascosilva volumio[7012]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Dec 15 14:25:29 adminvascosilva volumio[7012]: info: New Spotify access token = BQDlhXB5p7taF156-Y0HY2uOQBNaxF8CJt2Lr9IvOBMH_tsi5YDwh3h48BQq82Vghi3LYDC_LRmtYqGr4BAblIg1c2_WWgkB-PYBosBtWA5B3p9ArkEK0IlczHQ3R_0a4_VaYpOz6Rn3O_YhnDPHL94AyjWBCxlUtibVwWtQP8KFwYtAaCsDj0R4bYrQcQkKAWBaRnWIY5ExzBAz04KNDJFOxNqELrK_mbyDxDOL5XU6FfIApB5RmkBHFkrRpa4BXPf6PzV63Pu7ueMb7FKcvIMoroOLmyTpYw2L2A Dec 15 14:25:29 adminvascosilva volumio[7012]: info: Spotify credentials grant success - running version from March 24, 2019 Dec 15 14:25:29 adminvascosilva go-librespot[7202]: time="2025-12-15T14:25:29Z" 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:25:29 adminvascosilva go-librespot[7202]: time="2025-12-15T14:25:29Z" 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:25:29 adminvascosilva go-librespot[7202]: time="2025-12-15T14:25:29Z" 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:25:29 adminvascosilva go-librespot[7202]: time="2025-12-15T14:25:29Z" level=info msg="zeroconf server listening on port 36491" Dec 15 14:25:29 adminvascosilva go-librespot[7202]: time="2025-12-15T14:25:29Z" level=debug msg="obtained new client token: AAC/d4VQnsLVvwX8hD5iI/nq54zadukeu71HkXwQ2eenBAHiXypLihV2qzzurGpDa6x7eUfRYmtE3m6LlBarhI9fRGSHtO8cjM9jamQ6NB5bnCQ5V6DMzaBGMv320rp57eOw01ut5W8mvCRrlMEIa+dJIyHU9K3xHVrrEL2WDbGtW66Ys7BSJDuuy6tlEsxz2k/ASPjOiC3w0puJG9rpR3Ax/EQwi/u8MpQ1d3RUTQWuz+/j4SF2OQ==" Dec 15 14:25:29 adminvascosilva volumio[7012]: info: CoreCommandRouter::volumioGetState Dec 15 14:25:29 adminvascosilva volumio[7012]: info: CorePlayQueue::getTrack 0 Dec 15 14:25:29 adminvascosilva go-librespot[7202]: time="2025-12-15T14:25:29Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Dec 15 14:25:29 adminvascosilva go-librespot[7202]: time="2025-12-15T14:25:29Z" level=debug msg="completed keyexchange" Dec 15 14:25:29 adminvascosilva go-librespot[7202]: time="2025-12-15T14:25:29Z" level=debug msg="completed challenge" Dec 15 14:25:29 adminvascosilva volumio[7012]: 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:25:29 adminvascosilva volumio[7012]: info: Spotify Successfully logged in Dec 15 14:25:29 adminvascosilva go-librespot[7202]: time="2025-12-15T14:25:29Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TryAnotherAP " Dec 15 14:25:29 adminvascosilva systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 14:25:29 adminvascosilva systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 14:25:29 adminvascosilva volumio[7012]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Dec 15 14:25:29 adminvascosilva volumio[7012]: info: [1765808729643] CoreMusicLibrary::Adding element Spotify Dec 15 14:25:29 adminvascosilva volumio[7012]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 15 14:25:29 adminvascosilva volumio[7012]: Cannot find translation for source Spotify Dec 15 14:25:31 adminvascosilva mpd[7174]: 2025-12-15T14:25:31 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Dec 15 14:25:31 adminvascosilva systemd[1]: Started mpd.service - Music Player Daemon. Dec 15 14:25:31 adminvascosilva sudo[7153]: pam_unix(sudo:session): session closed for user root Dec 15 14:25:31 adminvascosilva sudo[7147]: pam_unix(sudo:session): session closed for user root Dec 15 14:25:31 adminvascosilva volumio[7012]: info: Completed starting Core Plugins Dec 15 14:25:31 adminvascosilva volumio[7012]: info: ------------------------------------------- Dec 15 14:25:31 adminvascosilva volumio[7012]: info: ----- MyVolumio plugins startup ---- Dec 15 14:25:31 adminvascosilva volumio[7012]: info: ------------------------------------------- Dec 15 14:25:31 adminvascosilva volumio[7012]: info: [MyVolumio PluginManager] Fetching plans data.... Dec 15 14:25:31 adminvascosilva volumio[7012]: error: MPD error: The expression evaluated to a falsy value: Dec 15 14:25:31 adminvascosilva volumio[7012]: assert.ok(self.idling) Dec 15 14:25:31 adminvascosilva volumio[7012]: error: The expression evaluated to a falsy value: Dec 15 14:25:31 adminvascosilva volumio[7012]: assert.ok(self.idling) Dec 15 14:25:31 adminvascosilva volumio[7012]: error: updateQueue error: null Dec 15 14:25:31 adminvascosilva volumio[7012]: info: MPD running with PID7174 Dec 15 14:25:31 adminvascosilva volumio[7012]: ,establishing connection Dec 15 14:25:31 adminvascosilva volumio[7012]: error: updateQueue error: null Dec 15 14:25:32 adminvascosilva volumio[7012]: info: go-librespot daemon successfully initialized Dec 15 14:25:32 adminvascosilva systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Dec 15 14:25:32 adminvascosilva systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:25:32 adminvascosilva systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:25:32 adminvascosilva go-librespot[7239]: go-librespot daemon starting... Dec 15 14:25:32 adminvascosilva go-librespot[7250]: time="2025-12-15T14:25:32Z" level=info msg="running go-librespot 0.4.0" Dec 15 14:25:32 adminvascosilva go-librespot[7250]: time="2025-12-15T14:25:32Z" level=debug msg="app state loaded" Dec 15 14:25:32 adminvascosilva go-librespot[7250]: time="2025-12-15T14:25:32Z" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 14:25:32 adminvascosilva sudo[7257]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 15 14:25:32 adminvascosilva sudo[7257]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:25:32 adminvascosilva sudo[7257]: pam_unix(sudo:session): session closed for user root Dec 15 14:25:33 adminvascosilva sudo[7259]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 15 14:25:33 adminvascosilva sudo[7259]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:25:33 adminvascosilva sudo[7259]: pam_unix(sudo:session): session closed for user root Dec 15 14:25:33 adminvascosilva sudo[7261]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Dec 15 14:25:33 adminvascosilva sudo[7261]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:25:33 adminvascosilva sudo[7261]: pam_unix(sudo:session): session closed for user root Dec 15 14:25:33 adminvascosilva volumio[7012]: info: Upmpdcli Daemon Started Dec 15 14:25:33 adminvascosilva go-librespot[7250]: time="2025-12-15T14:25:33Z" 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:25:33 adminvascosilva go-librespot[7250]: time="2025-12-15T14:25:33Z" 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:25:33 adminvascosilva go-librespot[7250]: time="2025-12-15T14:25:33Z" 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:25:33 adminvascosilva go-librespot[7250]: time="2025-12-15T14:25:33Z" level=info msg="zeroconf server listening on port 42567" Dec 15 14:25:33 adminvascosilva go-librespot[7250]: time="2025-12-15T14:25:33Z" level=debug msg="obtained new client token: AABMcjEhQ932KK2HtX1/7huUysGc6iZpbIlT7gKvMAB2x7ZuJXVjzfwYr8jGRpW7kIwZZVB23erLK54fGzxeYzmDFHqc7kcUrNg2zPdv5+7Zir6t0QVPYv9ybeZa+p4va3XdXtmzTJo4bK3azG6MuqSTc55/2CpX9YsigTS01lxG4zXaKTj9SWE5PM8CDx+U1Ps/An38wAZwwecuC1zMqV/0bQbSCIf9G6V51kiN+WPlTJYnCQMFHA==" Dec 15 14:25:33 adminvascosilva go-librespot[7250]: time="2025-12-15T14:25:33Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Dec 15 14:25:33 adminvascosilva go-librespot[7250]: time="2025-12-15T14:25:33Z" level=debug msg="completed keyexchange" Dec 15 14:25:33 adminvascosilva go-librespot[7250]: time="2025-12-15T14:25:33Z" level=debug msg="completed challenge" Dec 15 14:25:33 adminvascosilva go-librespot[7250]: time="2025-12-15T14:25:33Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TryAnotherAP " Dec 15 14:25:33 adminvascosilva systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 14:25:33 adminvascosilva systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 14:25:34 adminvascosilva sudo[7269]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 15 14:25:34 adminvascosilva sudo[7269]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:25:34 adminvascosilva sudo[7271]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Dec 15 14:25:34 adminvascosilva sudo[7271]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:25:34 adminvascosilva systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Dec 15 14:25:34 adminvascosilva systemd[1]: mpd_monitor.service: Deactivated successfully. Dec 15 14:25:34 adminvascosilva systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Dec 15 14:25:34 adminvascosilva systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Dec 15 14:25:34 adminvascosilva sudo[7269]: pam_unix(sudo:session): session closed for user root Dec 15 14:25:34 adminvascosilva sudo[7271]: pam_unix(sudo:session): session closed for user root Dec 15 14:25:34 adminvascosilva mpd_monitor.sh[7274]: MPD Monitor Service: Starting MPD Monitor Service Dec 15 14:25:34 adminvascosilva volumio[7012]: info: Successfully started MPD Monitor Dec 15 14:25:34 adminvascosilva volumio[7012]: info: Successfully started MPD Monitor Dec 15 14:25:34 adminvascosilva systemd[1]: Starting volumio-keepalive.service - Volumio KeepAlive (start playback if stopped)... Dec 15 14:25:34 adminvascosilva volumio[7012]: info: CoreCommandRouter::volumioGetState Dec 15 14:25:34 adminvascosilva volumio[7012]: info: CorePlayQueue::getTrack 0 Dec 15 14:25:35 adminvascosilva volumio[7012]: info: Initializing connection to go-librespot Websocket Dec 15 14:25:35 adminvascosilva volumio[7012]: info: Dec 15 14:25:35 adminvascosilva volumio[7012]: ---------------------------- Client requests Volumio play Dec 15 14:25:35 adminvascosilva volumio[7012]: info: CoreCommandRouter::volumioPlay Dec 15 14:25:35 adminvascosilva volumio[7012]: info: CoreStateMachine::play index undefined Dec 15 14:25:35 adminvascosilva volumio[7012]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 15 14:25:35 adminvascosilva volumio[7012]: info: CorePlayQueue::getTrack 0 Dec 15 14:25:35 adminvascosilva volumio[7012]: info: CoreStateMachine::startPlaybackTimer Dec 15 14:25:35 adminvascosilva volumio[7012]: info: CorePlayQueue::getTrack 0 Dec 15 14:25:35 adminvascosilva volumio[7012]: info: [1765808735130] ControllerSpotify::clearAddPlayTrack Dec 15 14:25:35 adminvascosilva volumio[7012]: info: Sending Spotify command with payload to local API: /player/play Dec 15 14:25:35 adminvascosilva volumio[7012]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 15 14:25:35 adminvascosilva volumio[7012]: error: Failed to send command to Spotify local API: /player/play: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 15 14:25:35 adminvascosilva systemd[1]: volumio-keepalive.service: Deactivated successfully. Dec 15 14:25:35 adminvascosilva systemd[1]: Finished volumio-keepalive.service - Volumio KeepAlive (start playback if stopped). Dec 15 14:25:36 adminvascosilva systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Dec 15 14:25:36 adminvascosilva systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:25:36 adminvascosilva systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:25:36 adminvascosilva go-librespot[7292]: go-librespot daemon starting... Dec 15 14:25:36 adminvascosilva volumio[7012]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Dec 15 14:25:36 adminvascosilva go-librespot[7293]: time="2025-12-15T14:25:36Z" level=info msg="running go-librespot 0.4.0" Dec 15 14:25:36 adminvascosilva go-librespot[7293]: time="2025-12-15T14:25:36Z" level=debug msg="app state loaded" Dec 15 14:25:36 adminvascosilva go-librespot[7293]: time="2025-12-15T14:25:36Z" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 14:25:36 adminvascosilva go-librespot[7293]: time="2025-12-15T14:25:36Z" level=debug msg="fetched new accesspoints: [ap-gew1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gae2.spotify.com:80]" Dec 15 14:25:36 adminvascosilva go-librespot[7293]: time="2025-12-15T14:25:36Z" level=debug msg="fetched new dealers: [gew1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Dec 15 14:25:36 adminvascosilva go-librespot[7293]: time="2025-12-15T14:25:36Z" level=debug msg="fetched new spclients: [gew1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Dec 15 14:25:36 adminvascosilva go-librespot[7293]: time="2025-12-15T14:25:36Z" level=info msg="zeroconf server listening on port 45927" Dec 15 14:25:36 adminvascosilva go-librespot[7293]: time="2025-12-15T14:25:36Z" level=debug msg="obtained new client token: AAAtuXp5iInH/if4iL498FYWOh4vItfvs+pPNYAeX8vwub/aNse+rZI0qHK0bG5SQPyMWy7cOwuwpg8LP/4F861qjrYTySdpKWLWD9g7voe6hAsPLJvIDLaCjd8T/SBKqWk+hQR85KLvmZHt/lM732u4UQIIj7a1Mg5tzMvefA3SQSgQcJUNXQAjKVhW/cD4PfDbfIhDivv5zLCmjxMQrNZ1D50GcIOIhLfIam/misMxdbtMLbmo+w==" Dec 15 14:25:37 adminvascosilva go-librespot[7293]: time="2025-12-15T14:25:37Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Dec 15 14:25:37 adminvascosilva go-librespot[7293]: time="2025-12-15T14:25:37Z" level=debug msg="completed keyexchange" Dec 15 14:25:37 adminvascosilva go-librespot[7293]: time="2025-12-15T14:25:37Z" level=debug msg="completed challenge" Dec 15 14:25:37 adminvascosilva go-librespot[7293]: time="2025-12-15T14:25:37Z" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: TryAnotherAP " Dec 15 14:25:37 adminvascosilva systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 14:25:37 adminvascosilva systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 14:25:38 adminvascosilva volumio[7012]: info: Initializing connection to go-librespot Websocket Dec 15 14:25:38 adminvascosilva volumio[7012]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 15 14:25:39 adminvascosilva volumio[7012]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Dec 15 14:25:39 adminvascosilva volumio[7012]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Dec 15 14:25:39 adminvascosilva volumio[7012]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Dec 15 14:25:39 adminvascosilva volumio[7012]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Dec 15 14:25:39 adminvascosilva volumio[7012]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Dec 15 14:25:39 adminvascosilva volumio[7012]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Dec 15 14:25:39 adminvascosilva volumio[7012]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Dec 15 14:25:39 adminvascosilva volumio[7012]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Dec 15 14:25:39 adminvascosilva volumio[7012]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Dec 15 14:25:39 adminvascosilva volumio[7012]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Dec 15 14:25:39 adminvascosilva volumio[7012]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Dec 15 14:25:39 adminvascosilva volumio[7012]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Dec 15 14:25:39 adminvascosilva volumio[7012]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Dec 15 14:25:39 adminvascosilva volumio[7012]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Dec 15 14:25:39 adminvascosilva volumio[7012]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Dec 15 14:25:39 adminvascosilva volumio[7012]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Dec 15 14:25:39 adminvascosilva volumio[7012]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Dec 15 14:25:39 adminvascosilva volumio[7012]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Dec 15 14:25:39 adminvascosilva volumio[7012]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Dec 15 14:25:39 adminvascosilva volumio[7012]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Dec 15 14:25:39 adminvascosilva volumio[7012]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Dec 15 14:25:39 adminvascosilva volumio[7012]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Dec 15 14:25:39 adminvascosilva volumio[7012]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Dec 15 14:25:39 adminvascosilva volumio[7012]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Dec 15 14:25:39 adminvascosilva volumio[7012]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Dec 15 14:25:39 adminvascosilva volumio[7012]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Dec 15 14:25:39 adminvascosilva volumio[7012]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Dec 15 14:25:39 adminvascosilva volumio[7012]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Dec 15 14:25:39 adminvascosilva volumio[7012]: info: Adding plugin bluetooth to MyMusic Plugins Dec 15 14:25:39 adminvascosilva volumio[7012]: info: Adding plugin multiroom to MyMusic Plugins Dec 15 14:25:39 adminvascosilva volumio[7012]: info: Adding plugin metavolumio to MyMusic Plugins Dec 15 14:25:39 adminvascosilva volumio[7012]: info: Adding plugin cd_controller to MyMusic Plugins Dec 15 14:25:39 adminvascosilva volumio[7012]: info: Adding plugin qobuzconnect to MyMusic Plugins Dec 15 14:25:39 adminvascosilva volumio[7012]: info: Adding plugin smart_inputs to MyMusic Plugins Dec 15 14:25:39 adminvascosilva volumio[7012]: info: Adding plugin tidalconnect to MyMusic Plugins Dec 15 14:25:39 adminvascosilva volumio[7012]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Dec 15 14:25:40 adminvascosilva systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Dec 15 14:25:40 adminvascosilva systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:25:40 adminvascosilva systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:25:40 adminvascosilva go-librespot[7301]: go-librespot daemon starting... Dec 15 14:25:40 adminvascosilva go-librespot[7302]: time="2025-12-15T14:25:40Z" level=info msg="running go-librespot 0.4.0" Dec 15 14:25:40 adminvascosilva go-librespot[7302]: time="2025-12-15T14:25:40Z" level=debug msg="app state loaded" Dec 15 14:25:40 adminvascosilva go-librespot[7302]: time="2025-12-15T14:25:40Z" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 14:25:40 adminvascosilva go-librespot[7302]: time="2025-12-15T14:25:40Z" 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:25:40 adminvascosilva go-librespot[7302]: time="2025-12-15T14:25:40Z" 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:25:40 adminvascosilva go-librespot[7302]: time="2025-12-15T14:25:40Z" 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:25:40 adminvascosilva go-librespot[7302]: time="2025-12-15T14:25:40Z" level=info msg="zeroconf server listening on port 38569" Dec 15 14:25:40 adminvascosilva go-librespot[7302]: time="2025-12-15T14:25:40Z" level=debug msg="obtained new client token: AACu5463qICs0vm8BL4UAJifutW4tZqxAb8c5ANuzD+KeCoi5hSFADMb3fAn+gnVobUKJjGB3jrUAYQHZVa10d1ZwXdWB0iY7Ouxmzaz+b1zoM9Yd3H7xmMibHYHlt2MMtJXciLoAPPX1tErzr2bg++rMeCIC4zcIxMBC/d5ZkRB3Cg4eEPqKPMPMJD46Yyj4GUzhnpbe8FkinFqfKt1VATRcbj0QavbKxsJ814fHTVpEl/f/lnqNA==" Dec 15 14:25:40 adminvascosilva volumio[7012]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Dec 15 14:25:40 adminvascosilva volumio[7012]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Dec 15 14:25:40 adminvascosilva go-librespot[7302]: time="2025-12-15T14:25:40Z" 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:25:40 adminvascosilva volumio[7012]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:25:40 adminvascosilva volumio[7012]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:25:40 adminvascosilva volumio[7012]: info: Starting MyVolumio Remote Streaming Endpoints Dec 15 14:25:40 adminvascosilva volumio[7012]: info: MyVolumio login type: Token Dec 15 14:25:40 adminvascosilva go-librespot[7302]: time="2025-12-15T14:25:40Z" level=debug msg="connected to ap-gew1.spotify.com:443" Dec 15 14:25:40 adminvascosilva volumio[7012]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Dec 15 14:25:40 adminvascosilva volumio[7012]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Dec 15 14:25:40 adminvascosilva go-librespot[7302]: time="2025-12-15T14:25:40Z" level=debug msg="completed keyexchange" Dec 15 14:25:40 adminvascosilva go-librespot[7302]: time="2025-12-15T14:25:40Z" level=debug msg="completed challenge" Dec 15 14:25:40 adminvascosilva go-librespot[7302]: time="2025-12-15T14:25:40Z" 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:25:40 adminvascosilva systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 14:25:41 adminvascosilva systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 14:25:41 adminvascosilva volumio[7012]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Dec 15 14:25:41 adminvascosilva volumio[7012]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Dec 15 14:25:41 adminvascosilva volumio[7012]: info: Streaming services startup Dec 15 14:25:41 adminvascosilva volumio[7012]: info: Starting Streaming Daemon Dec 15 14:25:41 adminvascosilva sudo[7310]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Dec 15 14:25:41 adminvascosilva sudo[7310]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:25:41 adminvascosilva volumio[7012]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Dec 15 14:25:41 adminvascosilva sudo[7310]: pam_unix(sudo:session): session closed for user root Dec 15 14:25:41 adminvascosilva volumio[7012]: info: Initializing connection to go-librespot Websocket Dec 15 14:25:41 adminvascosilva volumio[7012]: error: Cannot start Volumio Streaming Daemon Dec 15 14:25:41 adminvascosilva volumio[7012]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Dec 15 14:25:41 adminvascosilva volumio[7012]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Dec 15 14:25:41 adminvascosilva volumio[7012]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 15 14:25:42 adminvascosilva volumio[7012]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Dec 15 14:25:42 adminvascosilva volumio[7012]: info: MyVolumio token set successfully Dec 15 14:25:42 adminvascosilva volumio[7012]: info: MYVOLUMIO: Adding device Dec 15 14:25:42 adminvascosilva volumio[7012]: info: MYVOLUMIO: Evaluating Server Dec 15 14:25:43 adminvascosilva volumio[7012]: info: MyVolumio status changed Dec 15 14:25:43 adminvascosilva volumio[7012]: info: Streaming services startup Dec 15 14:25:43 adminvascosilva volumio[7012]: info: Starting Streaming Daemon Dec 15 14:25:43 adminvascosilva volumio[7012]: info: Removing browser output: myVolumio user plan is not superstar Dec 15 14:25:43 adminvascosilva volumio[7012]: info: Removing audio output: Dec 15 14:25:43 adminvascosilva volumio[7012]: info: Stoppping Tunnel 1 Dec 15 14:25:43 adminvascosilva sudo[7352]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Dec 15 14:25:43 adminvascosilva sudo[7352]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:25:43 adminvascosilva sudo[7352]: pam_unix(sudo:session): session closed for user root Dec 15 14:25:43 adminvascosilva sudo[7355]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Dec 15 14:25:43 adminvascosilva sudo[7355]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 15 14:25:43 adminvascosilva volumio[7012]: error: Cannot start Volumio Streaming Daemon Dec 15 14:25:43 adminvascosilva volumio[7012]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Dec 15 14:25:43 adminvascosilva volumio[7012]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Dec 15 14:25:43 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:25:43 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:25:43 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:25:43 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:25:43 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:25:43 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:25:43 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:25:43 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:25:43 adminvascosilva sudo[7355]: pam_unix(sudo:session): session closed for user root Dec 15 14:25:43 adminvascosilva volumio[7012]: info: Remote SSH Stopped Dec 15 14:25:43 adminvascosilva volumio[7012]: info: Setting Geolocation for MyVolumio to eu3 Dec 15 14:25:43 adminvascosilva volumio[7012]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:25:43 adminvascosilva volumio[7012]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:25:43 adminvascosilva volumio[7012]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:25:43 adminvascosilva volumio[7012]: info: Successfully Added MyVolumio device Dec 15 14:25:44 adminvascosilva systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Dec 15 14:25:44 adminvascosilva systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:25:44 adminvascosilva systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Dec 15 14:25:44 adminvascosilva go-librespot[7357]: go-librespot daemon starting... Dec 15 14:25:44 adminvascosilva go-librespot[7358]: time="2025-12-15T14:25:44Z" level=info msg="running go-librespot 0.4.0" Dec 15 14:25:44 adminvascosilva go-librespot[7358]: time="2025-12-15T14:25:44Z" level=debug msg="app state loaded" Dec 15 14:25:44 adminvascosilva go-librespot[7358]: time="2025-12-15T14:25:44Z" level=info msg="api server listening on 127.0.0.1:9879" Dec 15 14:25:44 adminvascosilva go-librespot[7358]: time="2025-12-15T14:25:44Z" 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:25:44 adminvascosilva go-librespot[7358]: time="2025-12-15T14:25:44Z" 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:25:44 adminvascosilva go-librespot[7358]: time="2025-12-15T14:25:44Z" 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:25:44 adminvascosilva go-librespot[7358]: time="2025-12-15T14:25:44Z" level=info msg="zeroconf server listening on port 37741" Dec 15 14:25:44 adminvascosilva volumio[7012]: info: Updating MyVolumio device info Dec 15 14:25:44 adminvascosilva volumio[7012]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:25:44 adminvascosilva volumio[7012]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:25:44 adminvascosilva volumio[7012]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 15 14:25:44 adminvascosilva go-librespot[7358]: time="2025-12-15T14:25:44Z" level=debug msg="obtained new client token: AADaUs0DBRdluz0BzLO6oXpjX/aVD7hn69xMdRDH5dtZbnERjqdwIGml60eP/8zjzV8iKEFNA7HSF1gSmjY7lQLuV+wsb/vom41Ykxh1RHyI6HE4axBnmnakpaRHb7jtQpj9v0RhD2/zKlNRPpH0b30ho6EXMFlIBp0HvGom4bPib9o5eMhIgICw0CFuV1j8AZXGvJL1NiG+aNmPDJplp0HpKiKCO89EBxlhixByKyWkHSVjEqq3Vg==" Dec 15 14:25:44 adminvascosilva go-librespot[7358]: time="2025-12-15T14:25:44Z" level=debug msg="connected to ap-gew1.spotify.com:4070" Dec 15 14:25:44 adminvascosilva go-librespot[7358]: time="2025-12-15T14:25:44Z" level=debug msg="completed keyexchange" Dec 15 14:25:44 adminvascosilva go-librespot[7358]: time="2025-12-15T14:25:44Z" level=debug msg="completed challenge" Dec 15 14:25:44 adminvascosilva volumio[7012]: info: Successfully Updated MyVolumio device Dec 15 14:25:44 adminvascosilva volumio[7012]: info: Initializing connection to go-librespot Websocket Dec 15 14:25:44 adminvascosilva go-librespot[7358]: time="2025-12-15T14:25:44Z" level=debug msg="new websocket client" Dec 15 14:25:44 adminvascosilva volumio[7012]: info: Connection to go-librespot Websocket established Dec 15 14:25:47 adminvascosilva go-librespot[7358]: time="2025-12-15T14:25:47Z" 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:25:47 adminvascosilva systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Dec 15 14:25:47 adminvascosilva systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Dec 15 14:25:47 adminvascosilva volumio[7012]: info: Connection to go-librespot Websocket closed Dec 15 14:25:47 adminvascosilva volumio[7012]: info: AutoStart - Plugin is starting Dec 15 14:25:47 adminvascosilva volumio[7012]: info: CoreCommandRouter::volumioGetQueue Dec 15 14:25:47 adminvascosilva volumio[7012]: info: CoreStateMachine::getQueue Dec 15 14:25:47 adminvascosilva volumio[7012]: info: CorePlayQueue::getQueue Dec 15 14:25:47 adminvascosilva volumio[7012]: info: AutoStart - start playing Dec 15 14:25:47 adminvascosilva volumio[7012]: info: AutoStart - start playing with no specific position Dec 15 14:25:47 adminvascosilva volumio[7012]: info: CoreCommandRouter::volumioPlay Dec 15 14:25:47 adminvascosilva volumio[7012]: info: CoreStateMachine::play index 0 Dec 15 14:25:47 adminvascosilva volumio[7012]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 15 14:25:47 adminvascosilva volumio[7012]: info: CoreStateMachine::stop Dec 15 14:25:47 adminvascosilva volumio[7012]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 15 14:25:47 adminvascosilva volumio[7012]: info: CoreStateMachine::play index undefined Dec 15 14:25:47 adminvascosilva volumio[7012]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 15 14:25:47 adminvascosilva volumio[7012]: info: CorePlayQueue::getTrack 0 Dec 15 14:25:47 adminvascosilva volumio[7012]: info: CoreStateMachine::startPlaybackTimer Dec 15 14:25:47 adminvascosilva volumio[7012]: info: CorePlayQueue::getTrack 0 Dec 15 14:25:47 adminvascosilva volumio[7012]: info: [1765808747948] ControllerSpotify::clearAddPlayTrack Dec 15 14:25:47 adminvascosilva volumio[7012]: info: Sending Spotify command with payload to local API: /player/play Dec 15 14:25:47 adminvascosilva volumio[7012]: error: Failed to send command to Spotify local API: /player/play: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 15 14:25:48 adminvascosilva volumio[7012]: info: Getting Spotify volume Dec 15 14:25:48 adminvascosilva volumio[7012]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 15 14:25:48 adminvascosilva volumio[7012]: Error: connect ECONNREFUSED 127.0.0.1:9879 Dec 15 14:25:48 adminvascosilva volumio[7012]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Dec 15 14:25:48 adminvascosilva volumio[7012]: errno: -111, Dec 15 14:25:48 adminvascosilva volumio[7012]: code: 'ECONNREFUSED', Dec 15 14:25:48 adminvascosilva volumio[7012]: syscall: 'connect', Dec 15 14:25:48 adminvascosilva volumio[7012]: address: '127.0.0.1', Dec 15 14:25:48 adminvascosilva volumio[7012]: port: 9879, Dec 15 14:25:48 adminvascosilva volumio[7012]: response: undefined Dec 15 14:25:48 adminvascosilva volumio[7012]: } Dec 15 14:25:48 adminvascosilva volumio[7012]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 15 14:25:48 adminvascosilva sudo[7379]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-15 14:24' Dec 15 14:25:48 adminvascosilva sudo[7379]: 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"