Jan 28 01:30:00 music systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 01:30:00 music go-librespot[5682]: time="2026-01-28T01:30:00-05:00" level=debug msg="completed keyexchange" Jan 28 01:30:00 music go-librespot[5682]: time="2026-01-28T01:30:00-05:00" level=debug msg="completed challenge" Jan 28 01:30:00 music sudo[5694]: pam_unix(sudo:session): session closed for user root Jan 28 01:30:00 music go-librespot[5682]: time="2026-01-28T01:30:00-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 28 01:30:00 music systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 28 01:30:00 music systemd[1]: shairport-sync.service: Deactivated successfully. Jan 28 01:30:00 music systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 01:30:00 music systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 01:30:00 music sudo[5697]: pam_unix(sudo:session): session closed for user root Jan 28 01:30:00 music sudo[5699]: pam_unix(sudo:session): session closed for user root Jan 28 01:30:00 music volumio[5487]: info: Shairport-Sync Started Jan 28 01:30:00 music volumio[5487]: Error adding Membership: Error: addMembership EINVAL Jan 28 01:30:00 music volumio[5487]: info: Shairport-Sync Started Jan 28 01:30:00 music volumio[5487]: info: Shairport-Sync Started Jan 28 01:30:00 music volumio[5487]: info: CoreCommandRouter::volumioGetState Jan 28 01:30:00 music volumio[5487]: info: CorePlayQueue::getTrack 0 Jan 28 01:30:00 music go-librespot[5682]: time="2026-01-28T01:30:00-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Jan 28 01:30:00 music volumio[5487]: info: CoreCommandRouter::volumioGetState Jan 28 01:30:00 music volumio[5487]: info: CorePlayQueue::getTrack 0 Jan 28 01:30:00 music go-librespot[5682]: time="2026-01-28T01:30:00-05:00" level=debug msg="completed keyexchange" Jan 28 01:30:00 music go-librespot[5682]: time="2026-01-28T01:30:00-05:00" level=debug msg="completed challenge" Jan 28 01:30:00 music go-librespot[5682]: time="2026-01-28T01:30:00-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 28 01:30:01 music go-librespot[5682]: time="2026-01-28T01:30:01-05:00" level=debug msg="connected to ap-gue1.spotify.com:80" Jan 28 01:30:01 music go-librespot[5682]: time="2026-01-28T01:30:01-05:00" level=debug msg="completed keyexchange" Jan 28 01:30:01 music go-librespot[5682]: time="2026-01-28T01:30:01-05:00" level=debug msg="completed challenge" Jan 28 01:30:01 music go-librespot[5682]: time="2026-01-28T01:30:01-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 28 01:30:01 music mpd[5656]: 2026-01-28T01:30:01 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 28 01:30:01 music systemd[1]: Started mpd.service - Music Player Daemon. Jan 28 01:30:01 music sudo[5617]: pam_unix(sudo:session): session closed for user root Jan 28 01:30:01 music sudo[5627]: pam_unix(sudo:session): session closed for user root Jan 28 01:30:01 music volumio[5487]: info: Completed starting Core Plugins Jan 28 01:30:01 music volumio[5487]: info: ------------------------------------------- Jan 28 01:30:01 music volumio[5487]: info: ----- MyVolumio plugins startup ---- Jan 28 01:30:01 music volumio[5487]: info: ------------------------------------------- Jan 28 01:30:01 music volumio[5487]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 28 01:30:02 music volumio[5487]: error: MPD error: The expression evaluated to a falsy value: Jan 28 01:30:02 music volumio[5487]: assert.ok(self.idling) Jan 28 01:30:02 music volumio[5487]: error: The expression evaluated to a falsy value: Jan 28 01:30:02 music volumio[5487]: assert.ok(self.idling) Jan 28 01:30:02 music volumio[5487]: info: MPD running with PID5656 Jan 28 01:30:02 music volumio[5487]: ,establishing connection Jan 28 01:30:02 music volumio[5487]: error: updateQueue error: null Jan 28 01:30:02 music volumio[5487]: error: updateQueue error: null Jan 28 01:30:02 music go-librespot[5682]: time="2026-01-28T01:30:02-05:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 28 01:30:02 music go-librespot[5682]: time="2026-01-28T01:30:02-05:00" level=debug msg="completed keyexchange" Jan 28 01:30:02 music go-librespot[5682]: time="2026-01-28T01:30:02-05:00" level=debug msg="completed challenge" Jan 28 01:30:02 music go-librespot[5682]: time="2026-01-28T01:30:02-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 28 01:30:02 music volumio[5487]: info: go-librespot daemon successfully initialized Jan 28 01:30:02 music sudo[5770]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 28 01:30:02 music sudo[5770]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 01:30:02 music sudo[5770]: pam_unix(sudo:session): session closed for user root Jan 28 01:30:02 music go-librespot[5682]: time="2026-01-28T01:30:02-05:00" level=debug msg="connected to ap-gew1.spotify.com:443" Jan 28 01:30:02 music sudo[5772]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 28 01:30:02 music sudo[5772]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 01:30:02 music sudo[5772]: pam_unix(sudo:session): session closed for user root Jan 28 01:30:02 music sudo[5776]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 28 01:30:02 music sudo[5776]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 01:30:02 music sudo[5776]: pam_unix(sudo:session): session closed for user root Jan 28 01:30:02 music volumio[5487]: info: Upmpdcli Daemon Started Jan 28 01:30:03 music go-librespot[5682]: time="2026-01-28T01:30:03-05:00" level=debug msg="completed keyexchange" Jan 28 01:30:03 music go-librespot[5682]: time="2026-01-28T01:30:03-05:00" level=debug msg="completed challenge" Jan 28 01:30:03 music go-librespot[5682]: time="2026-01-28T01:30:03-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 28 01:30:03 music go-librespot[5682]: time="2026-01-28T01:30:03-05:00" level=debug msg="connected to ap-gew4.spotify.com:80" Jan 28 01:30:04 music go-librespot[5682]: time="2026-01-28T01:30:04-05:00" level=debug msg="completed keyexchange" Jan 28 01:30:04 music go-librespot[5682]: time="2026-01-28T01:30:04-05:00" level=debug msg="completed challenge" Jan 28 01:30:04 music go-librespot[5682]: time="2026-01-28T01:30:04-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 28 01:30:04 music go-librespot[5682]: time="2026-01-28T01:30:04-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 01:30:04 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 01:30:04 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 01:30:05 music sudo[5779]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Jan 28 01:30:05 music sudo[5779]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 01:30:05 music sudo[5781]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Jan 28 01:30:05 music sudo[5781]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 01:30:05 music systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Jan 28 01:30:05 music systemd[1]: mpd_monitor.service: Deactivated successfully. Jan 28 01:30:05 music systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Jan 28 01:30:05 music systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Jan 28 01:30:05 music sudo[5779]: pam_unix(sudo:session): session closed for user root Jan 28 01:30:05 music mpd_monitor.sh[5784]: MPD Monitor Service: Starting MPD Monitor Service Jan 28 01:30:05 music sudo[5781]: pam_unix(sudo:session): session closed for user root Jan 28 01:30:05 music volumio[5487]: info: Successfully started MPD Monitor Jan 28 01:30:05 music volumio[5487]: info: Successfully started MPD Monitor Jan 28 01:30:05 music volumio[5487]: info: Initializing connection to go-librespot Websocket Jan 28 01:30:05 music volumio[5487]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 01:30:07 music volumio[5487]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 28 01:30:07 music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Jan 28 01:30:07 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 01:30:07 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 01:30:07 music go-librespot[5788]: go-librespot daemon starting... Jan 28 01:30:07 music go-librespot[5789]: time="2026-01-28T01:30:07-05:00" level=info msg="running go-librespot 0.6.2" Jan 28 01:30:07 music go-librespot[5789]: time="2026-01-28T01:30:07-05:00" level=debug msg="app state loaded" Jan 28 01:30:07 music go-librespot[5789]: time="2026-01-28T01:30:07-05:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 01:30:07 music go-librespot[5789]: time="2026-01-28T01:30:07-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 01:30:07 music go-librespot[5789]: time="2026-01-28T01:30:07-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 01:30:07 music go-librespot[5789]: time="2026-01-28T01:30:07-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 01:30:07 music go-librespot[5789]: time="2026-01-28T01:30:07-05:00" level=info msg="zeroconf server listening on port 42023" Jan 28 01:30:07 music go-librespot[5789]: time="2026-01-28T01:30:07-05:00" level=debug msg="obtained new client token: AABygSmYZwohQlgH21a42Epjechi3DT6VhVwcwLTQQtyf7vRnbvwjN+WQDuSuBOQNuVixqgBJhVs2iW6hD2hb5o+4N+TufjxISoqS5D3B+wBB3lMuP6ps78C6voz1eVoonleRDtqAwfvzFBUSs17RxiTwtCg6vIvC82K+mNacchhGt9dws/cOPoD4iqsJSYEflgDP+tnNYJ8+dEeMTW9iemtvxiD466RQZVGaWcRhgENELwg28EOTDk=" Jan 28 01:30:08 music go-librespot[5789]: time="2026-01-28T01:30:08-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Jan 28 01:30:08 music go-librespot[5789]: time="2026-01-28T01:30:08-05:00" level=debug msg="completed keyexchange" Jan 28 01:30:08 music go-librespot[5789]: time="2026-01-28T01:30:08-05:00" level=debug msg="completed challenge" Jan 28 01:30:08 music go-librespot[5789]: time="2026-01-28T01:30:08-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 28 01:30:08 music volumio[5487]: info: Initializing connection to go-librespot Websocket Jan 28 01:30:08 music go-librespot[5789]: time="2026-01-28T01:30:08-05:00" level=debug msg="new websocket client" Jan 28 01:30:08 music volumio[5487]: info: Connection to go-librespot Websocket established Jan 28 01:30:08 music go-librespot[5789]: time="2026-01-28T01:30:08-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Jan 28 01:30:08 music go-librespot[5789]: time="2026-01-28T01:30:08-05:00" level=debug msg="completed keyexchange" Jan 28 01:30:08 music go-librespot[5789]: time="2026-01-28T01:30:08-05:00" level=debug msg="completed challenge" Jan 28 01:30:08 music go-librespot[5789]: time="2026-01-28T01:30:08-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 28 01:30:09 music go-librespot[5789]: time="2026-01-28T01:30:09-05:00" level=debug msg="connected to ap-gue1.spotify.com:80" Jan 28 01:30:09 music go-librespot[5789]: time="2026-01-28T01:30:09-05:00" level=debug msg="completed keyexchange" Jan 28 01:30:09 music go-librespot[5789]: time="2026-01-28T01:30:09-05:00" level=debug msg="completed challenge" Jan 28 01:30:09 music go-librespot[5789]: time="2026-01-28T01:30:09-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 28 01:30:10 music volumio[5487]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 28 01:30:10 music volumio[5487]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 28 01:30:10 music volumio[5487]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 28 01:30:10 music volumio[5487]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jan 28 01:30:10 music volumio[5487]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 28 01:30:10 music volumio[5487]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 28 01:30:10 music volumio[5487]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 28 01:30:10 music volumio[5487]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 28 01:30:10 music volumio[5487]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 28 01:30:10 music volumio[5487]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 28 01:30:10 music volumio[5487]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jan 28 01:30:10 music volumio[5487]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 28 01:30:10 music volumio[5487]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 28 01:30:10 music volumio[5487]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 28 01:30:10 music volumio[5487]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jan 28 01:30:10 music volumio[5487]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 28 01:30:10 music volumio[5487]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 28 01:30:10 music volumio[5487]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 28 01:30:10 music volumio[5487]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 28 01:30:10 music volumio[5487]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 28 01:30:10 music volumio[5487]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 28 01:30:10 music volumio[5487]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jan 28 01:30:10 music volumio[5487]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 28 01:30:10 music volumio[5487]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jan 28 01:30:10 music volumio[5487]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 28 01:30:10 music volumio[5487]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 28 01:30:10 music volumio[5487]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 28 01:30:10 music volumio[5487]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 28 01:30:10 music volumio[5487]: info: Adding plugin bluetooth to MyMusic Plugins Jan 28 01:30:10 music volumio[5487]: info: Adding plugin multiroom to MyMusic Plugins Jan 28 01:30:10 music volumio[5487]: info: Adding plugin metavolumio to MyMusic Plugins Jan 28 01:30:10 music volumio[5487]: info: Adding plugin cd_controller to MyMusic Plugins Jan 28 01:30:10 music volumio[5487]: info: Adding plugin qobuzconnect to MyMusic Plugins Jan 28 01:30:10 music volumio[5487]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 28 01:30:10 music volumio[5487]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 28 01:30:10 music volumio[5487]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 28 01:30:10 music go-librespot[5789]: time="2026-01-28T01:30:10-05:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 01:30:10 music go-librespot[5789]: time="2026-01-28T01:30:10-05:00" level=debug msg="completed keyexchange" Jan 28 01:30:10 music go-librespot[5789]: time="2026-01-28T01:30:10-05:00" level=debug msg="completed challenge" Jan 28 01:30:10 music go-librespot[5789]: time="2026-01-28T01:30:10-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 28 01:30:11 music volumio[5487]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 28 01:30:11 music volumio[5487]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 28 01:30:11 music volumio[5487]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 01:30:11 music volumio[5487]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 01:30:11 music volumio[5487]: info: Starting MyVolumio Remote Streaming Endpoints Jan 28 01:30:11 music volumio[5487]: info: MyVolumio login type: Token Jan 28 01:30:11 music go-librespot[5789]: time="2026-01-28T01:30:11-05:00" level=debug msg="connected to ap-gew1.spotify.com:443" Jan 28 01:30:11 music volumio[5487]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 28 01:30:11 music volumio[5487]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 28 01:30:11 music go-librespot[5789]: time="2026-01-28T01:30:11-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.3.63:53318->104.199.65.9:443: read: connection reset by peer" Jan 28 01:30:12 music go-librespot[5789]: time="2026-01-28T01:30:12-05:00" level=debug msg="connected to ap-gew4.spotify.com:80" Jan 28 01:30:12 music go-librespot[5789]: time="2026-01-28T01:30:12-05:00" level=debug msg="completed keyexchange" Jan 28 01:30:12 music go-librespot[5789]: time="2026-01-28T01:30:12-05:00" level=debug msg="completed challenge" Jan 28 01:30:12 music volumio[5487]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 28 01:30:12 music volumio[5487]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 28 01:30:12 music volumio[5487]: info: Streaming services startup Jan 28 01:30:12 music volumio[5487]: info: Starting Streaming Daemon Jan 28 01:30:12 music sudo[5799]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 28 01:30:12 music sudo[5799]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 01:30:12 music volumio[5487]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 28 01:30:12 music go-librespot[5789]: time="2026-01-28T01:30:12-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 28 01:30:12 music go-librespot[5789]: time="2026-01-28T01:30:12-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 01:30:12 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 01:30:12 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 01:30:12 music sudo[5799]: pam_unix(sudo:session): session closed for user root Jan 28 01:30:12 music volumio[5487]: info: Getting Spotify volume Jan 28 01:30:12 music volumio[5487]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 01:30:12 music volumio[5487]: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 01:30:12 music volumio[5487]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Jan 28 01:30:12 music volumio[5487]: errno: -111, Jan 28 01:30:12 music volumio[5487]: code: 'ECONNREFUSED', Jan 28 01:30:12 music volumio[5487]: syscall: 'connect', Jan 28 01:30:12 music volumio[5487]: address: '127.0.0.1', Jan 28 01:30:12 music volumio[5487]: port: 9879, Jan 28 01:30:12 music volumio[5487]: response: undefined Jan 28 01:30:12 music volumio[5487]: } Jan 28 01:30:12 music volumio[5487]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 01:30:13 music sudo[5833]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-28 01:29' Jan 28 01:30:13 music sudo[5833]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 01:30:13 music sudo[5833]: pam_unix(sudo:session): session closed for user root Jan 28 01:30:13 music volumio-remote-updater[1248]: [2026-01-28 01:30:13] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Jan 28 01:30:13 music volumio-remote-updater[1248]: [2026-01-28 01:30:13] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Jan 28 01:30:13 music systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 28 01:30:13 music systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 28 01:30:13 music systemd[1]: volumio.service: Consumed 26.408s CPU time. Jan 28 01:30:13 music systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 28 01:30:13 music systemd[1]: dynamicswap.service: Deactivated successfully. Jan 28 01:30:13 music systemd[1]: volumio.service: Scheduled restart job, restart counter is at 32205. Jan 28 01:30:13 music systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 28 01:30:13 music systemd[1]: Stopped volumio.service - Volumio Backend Module. Jan 28 01:30:13 music systemd[1]: volumio.service: Consumed 26.408s CPU time. Jan 28 01:30:13 music systemd[1]: Started volumio.service - Volumio Backend Module. Jan 28 01:30:13 music systemd[1]: dynamicswap.service: Deactivated successfully. Jan 28 01:30:15 music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Jan 28 01:30:15 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 01:30:15 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 01:30:15 music go-librespot[5864]: go-librespot daemon starting... Jan 28 01:30:15 music go-librespot[5865]: time="2026-01-28T01:30:15-05:00" level=info msg="running go-librespot 0.6.2" Jan 28 01:30:15 music go-librespot[5865]: time="2026-01-28T01:30:15-05:00" level=debug msg="app state loaded" Jan 28 01:30:15 music go-librespot[5865]: time="2026-01-28T01:30:15-05:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 01:30:15 music volumio[5849]: info: ------------------------------------------- Jan 28 01:30:15 music volumio[5849]: info: ----- Volumio3 ---- Jan 28 01:30:15 music volumio[5849]: info: ------------------------------------------- Jan 28 01:30:15 music volumio[5849]: info: ----- System startup ---- Jan 28 01:30:15 music volumio[5849]: info: ------------------------------------------- Jan 28 01:30:15 music go-librespot[5865]: time="2026-01-28T01:30:15-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 01:30:15 music go-librespot[5865]: time="2026-01-28T01:30:15-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 01:30:15 music go-librespot[5865]: time="2026-01-28T01:30:15-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 01:30:16 music go-librespot[5865]: time="2026-01-28T01:30:16-05:00" level=info msg="zeroconf server listening on port 37817" Jan 28 01:30:16 music go-librespot[5865]: time="2026-01-28T01:30:16-05:00" level=debug msg="obtained new client token: AAB1mCh13h/tLWDse+oe4p652Xw4I3+E3F5hYFapUEaL2dQ/I9Cg64Nxr80vgovuShWT6jxkQUWLR4G+iIEselO7QvbnNAgEb66R4PNpV1YATosqlBK9efjO9DfsEfDHkYHbdx7wsSqpz9ex0kWmrWtsdEDIDfEHfSanWIB20vcMNMS5D7e2aS6E4g1nBjskoJAhHysO7pskOck5URjKW9JL3+x1mi/xDGE710ViPrB66GDrfrN/" Jan 28 01:30:16 music go-librespot[5865]: time="2026-01-28T01:30:16-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Jan 28 01:30:16 music go-librespot[5865]: time="2026-01-28T01:30:16-05:00" level=debug msg="completed keyexchange" Jan 28 01:30:16 music go-librespot[5865]: time="2026-01-28T01:30:16-05:00" level=debug msg="completed challenge" Jan 28 01:30:16 music go-librespot[5865]: time="2026-01-28T01:30:16-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 28 01:30:16 music volumio[5849]: info: MYVOLUMIO Environment detected Jan 28 01:30:16 music volumio[5849]: info: Plugin folders cleanup Jan 28 01:30:16 music volumio[5849]: info: Scanning into folder /volumio/app/plugins/ Jan 28 01:30:16 music volumio[5849]: info: Scanning category audio_interface Jan 28 01:30:16 music volumio[5849]: info: Scanning category miscellanea Jan 28 01:30:16 music volumio[5849]: info: Scanning category music_service Jan 28 01:30:16 music volumio[5849]: info: Scanning category plugins.json Jan 28 01:30:16 music volumio[5849]: info: Scanning category system_controller Jan 28 01:30:16 music volumio[5849]: info: Scanning category user_interface Jan 28 01:30:16 music volumio[5849]: info: Scanning into folder /data/plugins/ Jan 28 01:30:16 music volumio[5849]: info: Scanning category music_service Jan 28 01:30:16 music volumio[5849]: info: Plugin folders cleanup completed Jan 28 01:30:16 music volumio[5849]: info: ------------------------------------------- Jan 28 01:30:16 music volumio[5849]: info: ----- Core plugins startup ---- Jan 28 01:30:16 music volumio[5849]: info: ------------------------------------------- Jan 28 01:30:16 music volumio[5849]: info: Loading plugins from folder /volumio/app/plugins/ Jan 28 01:30:16 music volumio[5849]: info: Adding plugin upnp to MyMusic Plugins Jan 28 01:30:16 music volumio[5849]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 28 01:30:16 music volumio[5849]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 28 01:30:16 music volumio[5849]: info: Loading plugins from folder /data/plugins/ Jan 28 01:30:16 music volumio[5849]: info: Loading plugin "system"... Jan 28 01:30:16 music volumio[5849]: info: Loading plugin "appearance"... Jan 28 01:30:16 music go-librespot[5865]: time="2026-01-28T01:30:16-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Jan 28 01:30:17 music go-librespot[5865]: time="2026-01-28T01:30:17-05:00" level=debug msg="completed keyexchange" Jan 28 01:30:17 music go-librespot[5865]: time="2026-01-28T01:30:17-05:00" level=debug msg="completed challenge" Jan 28 01:30:17 music go-librespot[5865]: time="2026-01-28T01:30:17-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 28 01:30:17 music go-librespot[5865]: time="2026-01-28T01:30:17-05:00" level=debug msg="connected to ap-gue1.spotify.com:80" Jan 28 01:30:17 music go-librespot[5865]: time="2026-01-28T01:30:17-05:00" level=debug msg="completed keyexchange" Jan 28 01:30:17 music go-librespot[5865]: time="2026-01-28T01:30:17-05:00" level=debug msg="completed challenge" Jan 28 01:30:17 music go-librespot[5865]: time="2026-01-28T01:30:17-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 28 01:30:17 music volumio[5849]: info: Loading plugin "network"... Jan 28 01:30:17 music volumio[5849]: info: Refreshing Cached IP Addresses Jan 28 01:30:17 music sudo[5887]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 28 01:30:17 music sudo[5887]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 01:30:17 music sudo[5889]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 28 01:30:17 music sudo[5889]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 01:30:17 music sudo[5887]: pam_unix(sudo:session): session closed for user root Jan 28 01:30:17 music sudo[5889]: pam_unix(sudo:session): session closed for user root Jan 28 01:30:17 music volumio[5849]: info: Loading plugin "services"... Jan 28 01:30:17 music volumio[5849]: info: Loading plugin "alsa_controller"... Jan 28 01:30:17 music sudo[5898]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 28 01:30:17 music sudo[5898]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 01:30:18 music volumio[5849]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 01:30:18 music volumio[5849]: info: Loading plugin "wizard"... Jan 28 01:30:18 music volumio[5849]: info: Loading plugin "networkfs"... Jan 28 01:30:18 music volumio[5849]: info: Starting Udev Watcher for removable devices Jan 28 01:30:18 music volumio[5849]: info: Ignoring mount for partition: boot Jan 28 01:30:18 music volumio[5849]: info: Ignoring mount for partition: volumio Jan 28 01:30:18 music volumio[5849]: info: Ignoring mount for partition: volumio_data Jan 28 01:30:18 music volumio[5849]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 01:30:18 music volumio[5849]: info: Loading plugin "volumio_command_line_client"... Jan 28 01:30:18 music volumio[5849]: info: Loading plugin "upnp"... Jan 28 01:30:18 music volumio[5849]: info: [1769581818140] Starting Upmpd Daemon Jan 28 01:30:18 music volumio[5849]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 01:30:18 music volumio[5849]: info: Loading plugin "my_music"... Jan 28 01:30:18 music volumio[5849]: info: Loading plugin "mpd"... Jan 28 01:30:18 music go-librespot[5865]: time="2026-01-28T01:30:18-05:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 28 01:30:18 music go-librespot[5865]: time="2026-01-28T01:30:18-05:00" level=debug msg="completed keyexchange" Jan 28 01:30:18 music go-librespot[5865]: time="2026-01-28T01:30:18-05:00" level=debug msg="completed challenge" Jan 28 01:30:18 music volumio-remote-updater[1248]: [2026-01-28 01:30:18] [connect] Successful connection Jan 28 01:30:18 music go-librespot[5865]: time="2026-01-28T01:30:18-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 28 01:30:18 music volumio[5849]: info: Loading plugin "upnp_browser"... Jan 28 01:30:18 music sudo[5898]: pam_unix(sudo:session): session closed for user root Jan 28 01:30:19 music go-librespot[5865]: time="2026-01-28T01:30:19-05:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 28 01:30:19 music go-librespot[5865]: time="2026-01-28T01:30:19-05:00" level=debug msg="completed keyexchange" Jan 28 01:30:19 music go-librespot[5865]: time="2026-01-28T01:30:19-05:00" level=debug msg="completed challenge" Jan 28 01:30:19 music go-librespot[5865]: time="2026-01-28T01:30:19-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 28 01:30:20 music volumio[5849]: info: Starting UPNP Browser Jan 28 01:30:20 music volumio[5849]: info: Loading plugin "alarm-clock"... Jan 28 01:30:20 music volumio[5849]: info: Loading plugin "airplay_emulation"... Jan 28 01:30:20 music volumio[5849]: info: Starting Shairport Sync Jan 28 01:30:20 music volumio[5849]: info: Loading plugin "last_100"... Jan 28 01:30:20 music volumio[5849]: info: Loading plugin "webradio"... Jan 28 01:30:20 music go-librespot[5865]: time="2026-01-28T01:30:20-05:00" level=debug msg="connected to ap-gew4.spotify.com:80" Jan 28 01:30:20 music volumio[5849]: info: Loading plugin "i2s_dacs"... Jan 28 01:30:20 music volumio[5849]: info: I2S DAC not set, start Auto-detection Jan 28 01:30:20 music volumio[5849]: info: Loading plugin "volumiodiscovery"... Jan 28 01:30:20 music go-librespot[5865]: time="2026-01-28T01:30:20-05:00" level=debug msg="completed keyexchange" Jan 28 01:30:20 music go-librespot[5865]: time="2026-01-28T01:30:20-05:00" level=debug msg="completed challenge" Jan 28 01:30:20 music volumio[5849]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 28 01:30:20 music volumio[5849]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 01:30:20 music volumio[5849]: *** WARNING *** For more information see Jan 28 01:30:20 music volumio[5849]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 28 01:30:20 music volumio[5849]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 01:30:20 music volumio[5849]: *** WARNING *** For more information see Jan 28 01:30:20 music node[5849]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 28 01:30:20 music node[5849]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 01:30:20 music node[5849]: *** WARNING *** For more information see Jan 28 01:30:20 music node[5849]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 28 01:30:20 music node[5849]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 01:30:20 music node[5849]: *** WARNING *** For more information see Jan 28 01:30:20 music volumio[5849]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 28 01:30:20 music volumio[5849]: info: Discovery: Started advertising with name: music Jan 28 01:30:20 music volumio[5849]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 01:30:20 music volumio[5849]: info: Loading plugin "spop"... Jan 28 01:30:20 music go-librespot[5865]: time="2026-01-28T01:30:20-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 28 01:30:20 music go-librespot[5865]: time="2026-01-28T01:30:20-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 01:30:20 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 01:30:20 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 01:30:21 music volumio[5849]: info: Loading plugin "outputs"... Jan 28 01:30:21 music volumio[5849]: info: Loading plugin "albumart"... Jan 28 01:30:21 music volumio[5849]: info: Plugin example_plugin is not enabled Jan 28 01:30:21 music volumio[5849]: info: Loading plugin "inputs"... Jan 28 01:30:21 music volumio[5849]: info: Loading plugin "updater_comm"... Jan 28 01:30:21 music volumio[5849]: info: Plugin mpdemulation is not enabled Jan 28 01:30:21 music volumio[5849]: info: Loading plugin "rest_api"... Jan 28 01:30:21 music volumio[5849]: info: Loading plugin "websocket"... Jan 28 01:30:21 music volumio[5849]: info: Starting Socket.io Server version 1.7.4 Jan 28 01:30:21 music volumio[5849]: info: Loading i18n strings for locale en Jan 28 01:30:21 music volumio[5849]: Updating browse sources language Jan 28 01:30:21 music volumio[5849]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 01:30:21 music volumio[5849]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 01:30:21 music volumio[5849]: info: CoreCommandRouter::initPlayerControls Jan 28 01:30:21 music volumio[5849]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:30:21 music volumio[5849]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:30:21 music volumio[5849]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:30:21 music volumio[5849]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:30:21 music volumio[5849]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:30:21 music volumio[5849]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:30:21 music volumio[5849]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:30:21 music volumio[5849]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:30:21 music volumio[5849]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 01:30:21 music volumio[5849]: Express server listening on port 3000 Jan 28 01:30:21 music volumio[5849]: [Metrics] WebUI: 6s 655.68ms Jan 28 01:30:22 music volumio[5849]: info: CoreStateMachine::resetVolumioState Jan 28 01:30:22 music volumio[5849]: info: CoreStateMachine::getcurrentVolume Jan 28 01:30:22 music volumio[5849]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 01:30:22 music volumio[5849]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 01:30:22 music volumio[5849]: info: Volumio Network Manager: Network status updated: 1 Jan 28 01:30:22 music volumio-remote-updater[1248]: [2026-01-28 01:30:22] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1769581818 101 Jan 28 01:30:22 music volumio[5922]: Forking 3 albumart workers Jan 28 01:30:22 music volumio[5849]: 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 Jan 28 01:30:22 music volumio[5849]: info: VolumeController:: Volume=86 Mute =false Jan 28 01:30:22 music volumio[5849]: info: CoreStateMachine::pushState Jan 28 01:30:22 music volumio[5849]: info: CorePlayQueue::getTrack 0 Jan 28 01:30:22 music volumio[5849]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 01:30:22 music volumio[5849]: info: CoreCommandRouter::volumioPushState Jan 28 01:30:22 music volumio[5849]: info: CoreStateMachine::updateTrackBlock Jan 28 01:30:22 music volumio[5849]: info: CorePlayQueue::getTrackBlock Jan 28 01:30:22 music volumio[5849]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 01:30:22 music volumio[5849]: info: Reloading queue from file Jan 28 01:30:22 music volumio[5849]: info: CoreCommandRouter::volumioGetState Jan 28 01:30:22 music volumio[5849]: info: CorePlayQueue::getTrack 0 Jan 28 01:30:22 music volumio[5849]: info: CoreStateMachine::setRepeat null single undefined Jan 28 01:30:22 music volumio[5849]: info: CoreStateMachine::pushState Jan 28 01:30:22 music volumio[5849]: info: CorePlayQueue::getTrack 0 Jan 28 01:30:22 music volumio[5849]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 01:30:22 music volumio[5849]: info: CoreCommandRouter::volumioPushState Jan 28 01:30:22 music volumio[5849]: info: CoreStateMachine::setRandom null Jan 28 01:30:22 music volumio[5849]: info: CoreStateMachine::pushState Jan 28 01:30:22 music volumio[5849]: info: CorePlayQueue::getTrack 0 Jan 28 01:30:22 music volumio[5849]: info: CoreCommandRouter::volumioPushState Jan 28 01:30:22 music volumio[5849]: info: Setting Device type: Raspberry PI Jan 28 01:30:22 music volumio[5849]: info: Listing playlists Jan 28 01:30:22 music volumio[5849]: info: Listing playlists Jan 28 01:30:22 music volumio[5849]: info: VolumeController:: Volume=86 Mute =false Jan 28 01:30:22 music volumio[5849]: info: CoreStateMachine::pushState Jan 28 01:30:22 music volumio[5849]: info: CorePlayQueue::getTrack 0 Jan 28 01:30:22 music volumio[5849]: info: CoreCommandRouter::volumioPushState Jan 28 01:30:22 music volumio[5849]: info: Completed loading Core Plugins Jan 28 01:30:22 music volumio[5849]: info: Preparing to generate the ALSA configuration file Jan 28 01:30:22 music volumio[5849]: info: Discovery: adding 4a29b7a7-c637-4926-a2bd-fb4e2f55145e Jan 28 01:30:22 music volumio[5849]: info: Discovery: Found device music Jan 28 01:30:22 music volumio[5849]: info: CoreCommandRouter::volumioGetState Jan 28 01:30:22 music volumio[5849]: info: CorePlayQueue::getTrack 0 Jan 28 01:30:22 music volumio[5849]: info: Discovery: this is already registered, 4a29b7a7-c637-4926-a2bd-fb4e2f55145e Jan 28 01:30:22 music volumio[5849]: info: Discovery: Found device music Jan 28 01:30:22 music volumio[5849]: info: CoreCommandRouter::volumioGetState Jan 28 01:30:22 music volumio[5849]: info: CorePlayQueue::getTrack 0 Jan 28 01:30:22 music volumio[5849]: info: Asound.conf file unchanged, so no further update is needed Jan 28 01:30:22 music volumio[5849]: info: Output device has changed, restarting MPD Jan 28 01:30:22 music volumio[5849]: info: Output device has changed, restarting Shairport Sync Jan 28 01:30:22 music volumio[5849]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:30:22 music volumio[5849]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 01:30:22 music sudo[5978]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 28 01:30:22 music sudo[5978]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 01:30:22 music sudo[5978]: pam_unix(sudo:session): session closed for user root Jan 28 01:30:22 music sudo[5979]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 28 01:30:22 music sudo[5979]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 01:30:22 music volumio[5849]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 01:30:22 music volumio[5849]: info: ___________ START PLUGINS ___________ Jan 28 01:30:22 music volumio[5849]: info: ControllerMpd::onStart: Initializing MPD Jan 28 01:30:22 music volumio[5849]: info: Creating MPD Configuration file Jan 28 01:30:22 music volumio[5849]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 01:30:22 music volumio[5849]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 01:30:22 music volumio[5849]: info: [1769581822740] CoreMusicLibrary::Adding element Media Servers Jan 28 01:30:22 music volumio[5849]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 01:30:22 music systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 28 01:30:22 music volumio[5849]: info: UPNP Browser: Client initialized successfully Jan 28 01:30:22 music sudo[5988]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 28 01:30:22 music sudo[5988]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 01:30:22 music sudo[5989]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 28 01:30:22 music sudo[5989]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 01:30:22 music volumio[5849]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:30:22 music volumio[5849]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 01:30:22 music systemd[1]: mpd.service: Deactivated successfully. Jan 28 01:30:22 music sudo[5988]: pam_unix(sudo:session): session closed for user root Jan 28 01:30:22 music systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 28 01:30:22 music systemd[1]: mpd.service: Consumed 4.207s CPU time. Jan 28 01:30:22 music systemd[1]: mpd.socket: Deactivated successfully. Jan 28 01:30:22 music systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 28 01:30:22 music systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 28 01:30:22 music volumio[5849]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 01:30:22 music volumio[5849]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:30:22 music volumio[5849]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 01:30:22 music volumio[5849]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 01:30:22 music volumio[5849]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 01:30:22 music volumio[5849]: info: [1769581822894] CoreMusicLibrary::Adding element Last_100 Jan 28 01:30:22 music volumio[5849]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 01:30:22 music volumio[5849]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 01:30:22 music volumio[5849]: info: [1769581822900] CoreMusicLibrary::Adding element Webradio Jan 28 01:30:22 music volumio[5849]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 01:30:22 music systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 28 01:30:22 music volumio[5849]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 01:30:22 music systemd[1]: Starting mpd.service - Music Player Daemon... Jan 28 01:30:22 music volumio[5849]: info: Initializing BBC Radios Jan 28 01:30:22 music systemd[1]: mpd.service: Deactivated successfully. Jan 28 01:30:22 music systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 28 01:30:22 music systemd[1]: mpd.socket: Deactivated successfully. Jan 28 01:30:22 music systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 28 01:30:22 music systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 28 01:30:22 music systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 28 01:30:23 music systemd[1]: Starting mpd.service - Music Player Daemon... Jan 28 01:30:23 music volumio[5849]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 01:30:23 music volumio[5849]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 01:30:23 music volumio[5849]: info: Creating Spotify config file Jan 28 01:30:23 music volumio[5849]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:30:23 music sudo[6011]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 28 01:30:23 music sudo[6011]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 28 01:30:23 music sudo[6011]: pam_unix(sudo:session): session closed for user root Jan 28 01:30:23 music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Jan 28 01:30:23 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 01:30:23 music volumio[5849]: info: Volumio Calling Home Jan 28 01:30:23 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 01:30:23 music go-librespot[6019]: go-librespot daemon starting... Jan 28 01:30:23 music go-librespot[6022]: time="2026-01-28T01:30:23-05:00" level=info msg="running go-librespot 0.6.2" Jan 28 01:30:24 music volumio[5940]: Starting albumart workers Jan 28 01:30:24 music volumio[5938]: Starting albumart workers Jan 28 01:30:24 music go-librespot[6022]: time="2026-01-28T01:30:24-05:00" level=info msg="zeroconf server listening on port 38415" Jan 28 01:30:24 music volumio[5849]: info: MPD Permissions set Jan 28 01:30:24 music volumio[5849]: info: MPD Permissions set Jan 28 01:30:24 music volumio[5849]: info: Volumio called home Jan 28 01:30:24 music volumio[5849]: info: Spotify config file written Jan 28 01:30:24 music sudo[6034]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 28 01:30:24 music sudo[6034]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 01:30:24 music volumio[5939]: Starting albumart workers Jan 28 01:30:24 music systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Jan 28 01:30:24 music systemd[1]: go-librespot-daemon.service: Deactivated successfully. Jan 28 01:30:24 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 01:30:24 music volumio[5849]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Jan 28 01:30:24 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 01:30:24 music volumio[5849]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:30:24 music volumio[5849]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:30:24 music go-librespot[6036]: go-librespot daemon starting... Jan 28 01:30:24 music volumio[5849]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:30:24 music volumio[5849]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:30:24 music sudo[6034]: pam_unix(sudo:session): session closed for user root Jan 28 01:30:24 music volumio[5849]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:30:24 music volumio[5849]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:30:24 music volumio[5849]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:30:24 music volumio[5849]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:30:24 music volumio[5849]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 01:30:24 music volumio[5849]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:30:24 music go-librespot[6037]: time="2026-01-28T01:30:24-05:00" level=info msg="running go-librespot 0.6.2" Jan 28 01:30:24 music go-librespot[6037]: time="2026-01-28T01:30:24-05:00" level=debug msg="app state loaded" Jan 28 01:30:24 music volumio[5849]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:30:24 music volumio[5849]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:30:24 music volumio[5849]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:30:24 music volumio[5849]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:30:24 music volumio[5849]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:30:24 music volumio[5849]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:30:24 music volumio[5849]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:30:24 music volumio[5849]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:30:24 music volumio[5849]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 01:30:24 music volumio[5849]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:30:24 music go-librespot[6037]: time="2026-01-28T01:30:24-05:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 01:30:24 music volumio[5849]: info: No need to fix Spotify hosts Jan 28 01:30:25 music go-librespot[6037]: time="2026-01-28T01:30:25-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew1.spotify.com:80]" Jan 28 01:30:25 music go-librespot[6037]: time="2026-01-28T01:30:25-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 28 01:30:25 music go-librespot[6037]: time="2026-01-28T01:30:25-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 28 01:30:25 music go-librespot[6037]: time="2026-01-28T01:30:25-05:00" level=info msg="zeroconf server listening on port 33235" Jan 28 01:30:25 music go-librespot[6037]: time="2026-01-28T01:30:25-05:00" level=debug msg="obtained new client token: AAB9wNT8Iv0aa7UM2WqAAIZedPWZI661pF/AlHqMzx6MmahLUdr/00NLHjVinh4bw5AcPbc2V4k9DK90mjc7fUt0uKU4KDByMG47BIVquZbMPKDRmNZ3oz2NkNJ0RroLbRXbIatEuslNFiQWq6rrU4eiHWPyekgMJUOCkBWZzINdNQDH1S0eS8i5I9oeThgQW54BnKmuvOd+h5SMTVbqLR6UeNHzPQ+370Oq6kgRAbH1TxXc6hvl/0k=" Jan 28 01:30:25 music volumio[5849]: info: An error occurred while refreshing Spotify Token Error: Bad Request Jan 28 01:30:25 music volumio[5849]: info: Starting Shairport Sync Jan 28 01:30:25 music go-librespot[6037]: time="2026-01-28T01:30:25-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Jan 28 01:30:25 music volumio[5849]: info: Starting Shairport Sync Jan 28 01:30:25 music volumio[5849]: info: Starting Shairport Sync Jan 28 01:30:25 music sudo[6071]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 01:30:25 music sudo[6071]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 01:30:25 music go-librespot[6037]: time="2026-01-28T01:30:25-05:00" level=debug msg="completed keyexchange" Jan 28 01:30:25 music go-librespot[6037]: time="2026-01-28T01:30:25-05:00" level=debug msg="completed challenge" Jan 28 01:30:25 music systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 28 01:30:25 music systemd[1]: shairport-sync.service: Deactivated successfully. Jan 28 01:30:25 music systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 01:30:25 music systemd[1]: shairport-sync.service: Consumed 1.801s CPU time. Jan 28 01:30:25 music sudo[6073]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 01:30:25 music sudo[6073]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 01:30:25 music sudo[6076]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 01:30:25 music sudo[6076]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 01:30:25 music go-librespot[6037]: time="2026-01-28T01:30:25-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 28 01:30:25 music systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 01:30:25 music volumio[5849]: info: CoreCommandRouter::volumioGetState Jan 28 01:30:25 music volumio[5849]: info: CorePlayQueue::getTrack 0 Jan 28 01:30:25 music sudo[6071]: pam_unix(sudo:session): session closed for user root Jan 28 01:30:25 music volumio[5849]: info: Shairport-Sync Started Jan 28 01:30:25 music volumio[5849]: Error adding Membership: Error: addMembership EINVAL Jan 28 01:30:25 music systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 28 01:30:25 music systemd[1]: shairport-sync.service: Deactivated successfully. Jan 28 01:30:25 music systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 01:30:25 music systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 01:30:26 music sudo[6073]: pam_unix(sudo:session): session closed for user root Jan 28 01:30:26 music sudo[6076]: pam_unix(sudo:session): session closed for user root Jan 28 01:30:26 music volumio[5849]: info: Shairport-Sync Started Jan 28 01:30:26 music volumio[5849]: info: Shairport-Sync Started Jan 28 01:30:26 music go-librespot[6037]: time="2026-01-28T01:30:26-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Jan 28 01:30:26 music go-librespot[6037]: time="2026-01-28T01:30:26-05:00" level=debug msg="completed keyexchange" Jan 28 01:30:26 music go-librespot[6037]: time="2026-01-28T01:30:26-05:00" level=debug msg="completed challenge" Jan 28 01:30:26 music go-librespot[6037]: time="2026-01-28T01:30:26-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 28 01:30:27 music go-librespot[6037]: time="2026-01-28T01:30:27-05:00" level=debug msg="connected to ap-gue1.spotify.com:80" Jan 28 01:30:27 music go-librespot[6037]: time="2026-01-28T01:30:27-05:00" level=debug msg="completed keyexchange" Jan 28 01:30:27 music go-librespot[6037]: time="2026-01-28T01:30:27-05:00" level=debug msg="completed challenge" Jan 28 01:30:27 music go-librespot[6037]: time="2026-01-28T01:30:27-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 28 01:30:27 music mpd[6018]: 2026-01-28T01:30:27 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 28 01:30:27 music systemd[1]: Started mpd.service - Music Player Daemon. Jan 28 01:30:27 music sudo[5989]: pam_unix(sudo:session): session closed for user root Jan 28 01:30:27 music sudo[5979]: pam_unix(sudo:session): session closed for user root Jan 28 01:30:27 music volumio[5849]: info: Completed starting Core Plugins Jan 28 01:30:27 music volumio[5849]: info: ------------------------------------------- Jan 28 01:30:27 music volumio[5849]: info: ----- MyVolumio plugins startup ---- Jan 28 01:30:27 music volumio[5849]: info: ------------------------------------------- Jan 28 01:30:27 music volumio[5849]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 28 01:30:27 music volumio[5849]: error: MPD error: The expression evaluated to a falsy value: Jan 28 01:30:27 music volumio[5849]: assert.ok(self.idling) Jan 28 01:30:27 music volumio[5849]: error: The expression evaluated to a falsy value: Jan 28 01:30:27 music volumio[5849]: assert.ok(self.idling) Jan 28 01:30:27 music volumio[5849]: info: MPD running with PID6018 Jan 28 01:30:27 music volumio[5849]: ,establishing connection Jan 28 01:30:27 music volumio[5849]: error: updateQueue error: null Jan 28 01:30:27 music volumio[5849]: error: updateQueue error: null Jan 28 01:30:27 music go-librespot[6037]: time="2026-01-28T01:30:27-05:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 28 01:30:27 music go-librespot[6037]: time="2026-01-28T01:30:27-05:00" level=debug msg="completed keyexchange" Jan 28 01:30:27 music go-librespot[6037]: time="2026-01-28T01:30:27-05:00" level=debug msg="completed challenge" Jan 28 01:30:27 music go-librespot[6037]: time="2026-01-28T01:30:27-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 28 01:30:28 music sudo[6134]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 28 01:30:28 music sudo[6134]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 01:30:28 music sudo[6136]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 28 01:30:28 music sudo[6136]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 01:30:28 music sudo[6134]: pam_unix(sudo:session): session closed for user root Jan 28 01:30:28 music sudo[6136]: pam_unix(sudo:session): session closed for user root Jan 28 01:30:28 music sudo[6138]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 28 01:30:28 music sudo[6138]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 01:30:28 music sudo[6138]: pam_unix(sudo:session): session closed for user root Jan 28 01:30:28 music volumio[5849]: info: Upmpdcli Daemon Started Jan 28 01:30:28 music go-librespot[6037]: time="2026-01-28T01:30:28-05:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 28 01:30:28 music volumio[5849]: info: go-librespot daemon successfully initialized Jan 28 01:30:28 music go-librespot[6037]: time="2026-01-28T01:30:28-05:00" level=debug msg="completed keyexchange" Jan 28 01:30:28 music go-librespot[6037]: time="2026-01-28T01:30:28-05:00" level=debug msg="completed challenge" Jan 28 01:30:28 music go-librespot[6037]: time="2026-01-28T01:30:28-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 28 01:30:29 music go-librespot[6037]: time="2026-01-28T01:30:29-05:00" level=debug msg="connected to ap-gew1.spotify.com:80" Jan 28 01:30:29 music go-librespot[6037]: time="2026-01-28T01:30:29-05:00" level=debug msg="completed keyexchange" Jan 28 01:30:29 music go-librespot[6037]: time="2026-01-28T01:30:29-05:00" level=debug msg="completed challenge" Jan 28 01:30:29 music go-librespot[6037]: time="2026-01-28T01:30:29-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 28 01:30:29 music go-librespot[6037]: time="2026-01-28T01:30:29-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 01:30:29 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 01:30:29 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 01:30:30 music sudo[6143]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Jan 28 01:30:30 music sudo[6143]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 01:30:30 music sudo[6146]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Jan 28 01:30:30 music sudo[6146]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 01:30:30 music systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Jan 28 01:30:30 music systemd[1]: mpd_monitor.service: Deactivated successfully. Jan 28 01:30:30 music systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Jan 28 01:30:30 music systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Jan 28 01:30:30 music sudo[6143]: pam_unix(sudo:session): session closed for user root Jan 28 01:30:30 music mpd_monitor.sh[6148]: MPD Monitor Service: Starting MPD Monitor Service Jan 28 01:30:30 music volumio[5849]: info: Successfully started MPD Monitor Jan 28 01:30:30 music systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Jan 28 01:30:30 music systemd[1]: mpd_monitor.service: Deactivated successfully. Jan 28 01:30:30 music systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Jan 28 01:30:30 music systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Jan 28 01:30:30 music sudo[6146]: pam_unix(sudo:session): session closed for user root Jan 28 01:30:30 music volumio[5849]: info: Successfully started MPD Monitor Jan 28 01:30:30 music mpd_monitor.sh[6152]: MPD Monitor Service: Starting MPD Monitor Service Jan 28 01:30:30 music volumio[5849]: info: CoreCommandRouter::volumioGetState Jan 28 01:30:30 music volumio[5849]: info: CorePlayQueue::getTrack 0 Jan 28 01:30:31 music volumio[5849]: info: Initializing connection to go-librespot Websocket Jan 28 01:30:31 music volumio[5849]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 01:30:32 music volumio[5849]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 28 01:30:33 music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Jan 28 01:30:33 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 01:30:33 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 01:30:33 music go-librespot[6156]: go-librespot daemon starting... Jan 28 01:30:33 music go-librespot[6157]: time="2026-01-28T01:30:33-05:00" level=info msg="running go-librespot 0.6.2" Jan 28 01:30:33 music go-librespot[6157]: time="2026-01-28T01:30:33-05:00" level=debug msg="app state loaded" Jan 28 01:30:33 music go-librespot[6157]: time="2026-01-28T01:30:33-05:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 01:30:33 music go-librespot[6157]: time="2026-01-28T01:30:33-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 01:30:33 music go-librespot[6157]: time="2026-01-28T01:30:33-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 01:30:33 music go-librespot[6157]: time="2026-01-28T01:30:33-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 01:30:33 music go-librespot[6157]: time="2026-01-28T01:30:33-05:00" level=info msg="zeroconf server listening on port 44287" Jan 28 01:30:33 music go-librespot[6157]: time="2026-01-28T01:30:33-05:00" level=debug msg="obtained new client token: AAAZoolE/qcfCD+Qvg9512lkagJ8i/1cXZ7I0A2dOPrMbp2CCRsbSIbfx6Xv7xS6vPFGT6yUZ7PZSv9oRTwhhSqpR32C5jQzlW350ha4V4QXOgBVkaNlOiz0mYwvZ5aN/raLLtF+O+JOBJXAZonNlje7kl/oUyc+mdUwtWr2wcvjSQZnpcdg5FmtebtzS6OAOHt0C50oS4HRkp4Y4Bf1SlxC38SzvRaZlEf+kuJOGqiTRDSpV2SNn8c=" Jan 28 01:30:33 music go-librespot[6157]: time="2026-01-28T01:30:33-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Jan 28 01:30:33 music go-librespot[6157]: time="2026-01-28T01:30:33-05:00" level=debug msg="completed keyexchange" Jan 28 01:30:33 music go-librespot[6157]: time="2026-01-28T01:30:33-05:00" level=debug msg="completed challenge" Jan 28 01:30:33 music go-librespot[6157]: time="2026-01-28T01:30:33-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 28 01:30:34 music go-librespot[6157]: time="2026-01-28T01:30:34-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Jan 28 01:30:34 music go-librespot[6157]: time="2026-01-28T01:30:34-05:00" level=debug msg="completed keyexchange" Jan 28 01:30:34 music go-librespot[6157]: time="2026-01-28T01:30:34-05:00" level=debug msg="completed challenge" Jan 28 01:30:34 music go-librespot[6157]: time="2026-01-28T01:30:34-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 28 01:30:34 music volumio[5849]: info: Initializing connection to go-librespot Websocket Jan 28 01:30:34 music go-librespot[6157]: time="2026-01-28T01:30:34-05:00" level=debug msg="new websocket client" Jan 28 01:30:34 music volumio[5849]: info: Connection to go-librespot Websocket established Jan 28 01:30:35 music go-librespot[6157]: time="2026-01-28T01:30:35-05:00" level=debug msg="connected to ap-gue1.spotify.com:80" Jan 28 01:30:35 music go-librespot[6157]: time="2026-01-28T01:30:35-05:00" level=debug msg="completed keyexchange" Jan 28 01:30:35 music go-librespot[6157]: time="2026-01-28T01:30:35-05:00" level=debug msg="completed challenge" Jan 28 01:30:35 music go-librespot[6157]: time="2026-01-28T01:30:35-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 28 01:30:35 music go-librespot[6157]: time="2026-01-28T01:30:35-05:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Jan 28 01:30:35 music volumio[5849]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 28 01:30:35 music volumio[5849]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 28 01:30:35 music volumio[5849]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 28 01:30:35 music volumio[5849]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jan 28 01:30:35 music volumio[5849]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 28 01:30:35 music volumio[5849]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 28 01:30:35 music volumio[5849]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 28 01:30:35 music volumio[5849]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 28 01:30:35 music volumio[5849]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 28 01:30:36 music volumio[5849]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 28 01:30:36 music volumio[5849]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jan 28 01:30:36 music volumio[5849]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 28 01:30:36 music volumio[5849]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 28 01:30:36 music volumio[5849]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 28 01:30:36 music volumio[5849]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jan 28 01:30:36 music volumio[5849]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 28 01:30:36 music volumio[5849]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 28 01:30:36 music volumio[5849]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 28 01:30:36 music volumio[5849]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 28 01:30:36 music volumio[5849]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 28 01:30:36 music volumio[5849]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 28 01:30:36 music volumio[5849]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jan 28 01:30:36 music volumio[5849]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 28 01:30:36 music volumio[5849]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jan 28 01:30:36 music volumio[5849]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 28 01:30:36 music volumio[5849]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 28 01:30:36 music volumio[5849]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 28 01:30:36 music volumio[5849]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 28 01:30:36 music go-librespot[6157]: time="2026-01-28T01:30:36-05:00" level=debug msg="connected to ap-gew1.spotify.com:443" Jan 28 01:30:36 music volumio[5849]: info: Adding plugin bluetooth to MyMusic Plugins Jan 28 01:30:36 music volumio[5849]: info: Adding plugin multiroom to MyMusic Plugins Jan 28 01:30:36 music volumio[5849]: info: Adding plugin metavolumio to MyMusic Plugins Jan 28 01:30:36 music volumio[5849]: info: Adding plugin cd_controller to MyMusic Plugins Jan 28 01:30:36 music volumio[5849]: info: Adding plugin qobuzconnect to MyMusic Plugins Jan 28 01:30:36 music volumio[5849]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 28 01:30:36 music volumio[5849]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 28 01:30:36 music volumio[5849]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 28 01:30:36 music go-librespot[6157]: time="2026-01-28T01:30:36-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.3.63:43220->104.199.65.9:443: read: connection reset by peer" Jan 28 01:30:36 music go-librespot[6157]: time="2026-01-28T01:30:36-05:00" level=debug msg="connected to ap-gew4.spotify.com:80" Jan 28 01:30:36 music go-librespot[6157]: time="2026-01-28T01:30:36-05:00" level=debug msg="completed keyexchange" Jan 28 01:30:36 music go-librespot[6157]: time="2026-01-28T01:30:36-05:00" level=debug msg="completed challenge" Jan 28 01:30:36 music go-librespot[6157]: time="2026-01-28T01:30:36-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 28 01:30:37 music volumio[5849]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 28 01:30:37 music volumio[5849]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 28 01:30:37 music volumio[5849]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 01:30:37 music volumio[5849]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 01:30:37 music volumio[5849]: info: Starting MyVolumio Remote Streaming Endpoints Jan 28 01:30:37 music volumio[5849]: info: MyVolumio login type: Token Jan 28 01:30:37 music volumio[5849]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 28 01:30:37 music volumio[5849]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 28 01:30:37 music go-librespot[6157]: time="2026-01-28T01:30:37-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Jan 28 01:30:37 music go-librespot[6157]: time="2026-01-28T01:30:37-05:00" level=debug msg="completed keyexchange" Jan 28 01:30:37 music go-librespot[6157]: time="2026-01-28T01:30:37-05:00" level=debug msg="completed challenge" Jan 28 01:30:37 music go-librespot[6157]: time="2026-01-28T01:30:37-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 28 01:30:37 music go-librespot[6157]: time="2026-01-28T01:30:37-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 01:30:37 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 01:30:37 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 01:30:38 music volumio[5849]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 28 01:30:38 music volumio[5849]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 28 01:30:38 music volumio[5849]: info: Streaming services startup Jan 28 01:30:38 music volumio[5849]: info: Starting Streaming Daemon Jan 28 01:30:38 music sudo[6181]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 28 01:30:38 music sudo[6181]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 01:30:38 music volumio[5849]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 28 01:30:38 music sudo[6181]: pam_unix(sudo:session): session closed for user root Jan 28 01:30:38 music volumio[5849]: info: Getting Spotify volume Jan 28 01:30:38 music volumio[5849]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 01:30:38 music volumio[5849]: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 01:30:38 music volumio[5849]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Jan 28 01:30:38 music volumio[5849]: errno: -111, Jan 28 01:30:38 music volumio[5849]: code: 'ECONNREFUSED', Jan 28 01:30:38 music volumio[5849]: syscall: 'connect', Jan 28 01:30:38 music volumio[5849]: address: '127.0.0.1', Jan 28 01:30:38 music volumio[5849]: port: 9879, Jan 28 01:30:38 music volumio[5849]: response: undefined Jan 28 01:30:38 music volumio[5849]: } Jan 28 01:30:38 music volumio[5849]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 01:30:39 music sudo[6202]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-28 01:29' Jan 28 01:30:39 music sudo[6202]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 01:30:39 music sudo[6202]: pam_unix(sudo:session): session closed for user root Jan 28 01:30:39 music volumio-remote-updater[1248]: [2026-01-28 01:30:39] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Jan 28 01:30:39 music volumio-remote-updater[1248]: [2026-01-28 01:30:39] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Jan 28 01:30:39 music systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 28 01:30:39 music systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 28 01:30:39 music systemd[1]: volumio.service: Consumed 26.542s CPU time. Jan 28 01:30:39 music systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 28 01:30:39 music systemd[1]: dynamicswap.service: Deactivated successfully. Jan 28 01:30:39 music systemd[1]: volumio.service: Scheduled restart job, restart counter is at 32206. Jan 28 01:30:39 music systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 28 01:30:39 music systemd[1]: Stopped volumio.service - Volumio Backend Module. Jan 28 01:30:39 music systemd[1]: volumio.service: Consumed 26.542s CPU time. Jan 28 01:30:39 music systemd[1]: Started volumio.service - Volumio Backend Module. Jan 28 01:30:39 music systemd[1]: dynamicswap.service: Deactivated successfully. Jan 28 01:30:40 music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Jan 28 01:30:40 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 01:30:40 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 01:30:40 music go-librespot[6229]: go-librespot daemon starting... Jan 28 01:30:40 music go-librespot[6230]: time="2026-01-28T01:30:40-05:00" level=info msg="running go-librespot 0.6.2" Jan 28 01:30:40 music go-librespot[6230]: time="2026-01-28T01:30:40-05:00" level=debug msg="app state loaded" Jan 28 01:30:40 music go-librespot[6230]: time="2026-01-28T01:30:40-05:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 01:30:41 music go-librespot[6230]: time="2026-01-28T01:30:41-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 01:30:41 music go-librespot[6230]: time="2026-01-28T01:30:41-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 01:30:41 music go-librespot[6230]: time="2026-01-28T01:30:41-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 01:30:41 music go-librespot[6230]: time="2026-01-28T01:30:41-05:00" level=info msg="zeroconf server listening on port 43645" Jan 28 01:30:41 music go-librespot[6230]: time="2026-01-28T01:30:41-05:00" level=debug msg="obtained new client token: AAB6VgVuY4xj/Yjr68CGdZdYp9AwZNwPrbAj8DSBMw3JQO/7L6HLdDDpBkKPleVJ7fbz/wH/znX8hfpizdy4Yq4nV8lvuXaEyT/eVHX4MxSNqnEcO02XsYif+/49sZUl6ddRe9le8nSwAPsYXqUK4WBdsGGwYwhb0iinAHubxQg7YQmng5SjMoP2b/BtgiOtPKWIJWyzPQZ78bgIv9vu5HoTqFz5+nE1GjQABVQOyugmTruUsbFvF5s=" Jan 28 01:30:41 music go-librespot[6230]: time="2026-01-28T01:30:41-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Jan 28 01:30:41 music go-librespot[6230]: time="2026-01-28T01:30:41-05:00" level=debug msg="completed keyexchange" Jan 28 01:30:41 music go-librespot[6230]: time="2026-01-28T01:30:41-05:00" level=debug msg="completed challenge" Jan 28 01:30:41 music go-librespot[6230]: time="2026-01-28T01:30:41-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 28 01:30:41 music volumio[6214]: info: ------------------------------------------- Jan 28 01:30:41 music volumio[6214]: info: ----- Volumio3 ---- Jan 28 01:30:41 music volumio[6214]: info: ------------------------------------------- Jan 28 01:30:41 music volumio[6214]: info: ----- System startup ---- Jan 28 01:30:41 music volumio[6214]: info: ------------------------------------------- Jan 28 01:30:42 music go-librespot[6230]: time="2026-01-28T01:30:42-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Jan 28 01:30:42 music go-librespot[6230]: time="2026-01-28T01:30:42-05:00" level=debug msg="completed keyexchange" Jan 28 01:30:42 music go-librespot[6230]: time="2026-01-28T01:30:42-05:00" level=debug msg="completed challenge" Jan 28 01:30:42 music go-librespot[6230]: time="2026-01-28T01:30:42-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 28 01:30:42 music volumio[6214]: info: MYVOLUMIO Environment detected Jan 28 01:30:42 music volumio[6214]: info: Plugin folders cleanup Jan 28 01:30:42 music volumio[6214]: info: Scanning into folder /volumio/app/plugins/ Jan 28 01:30:42 music volumio[6214]: info: Scanning category audio_interface Jan 28 01:30:42 music volumio[6214]: info: Scanning category miscellanea Jan 28 01:30:42 music volumio[6214]: info: Scanning category music_service Jan 28 01:30:42 music volumio[6214]: info: Scanning category plugins.json Jan 28 01:30:42 music volumio[6214]: info: Scanning category system_controller Jan 28 01:30:42 music volumio[6214]: info: Scanning category user_interface Jan 28 01:30:42 music volumio[6214]: info: Scanning into folder /data/plugins/ Jan 28 01:30:42 music volumio[6214]: info: Scanning category music_service Jan 28 01:30:42 music volumio[6214]: info: Plugin folders cleanup completed Jan 28 01:30:42 music volumio[6214]: info: ------------------------------------------- Jan 28 01:30:42 music volumio[6214]: info: ----- Core plugins startup ---- Jan 28 01:30:42 music volumio[6214]: info: ------------------------------------------- Jan 28 01:30:42 music volumio[6214]: info: Loading plugins from folder /volumio/app/plugins/ Jan 28 01:30:42 music volumio[6214]: info: Adding plugin upnp to MyMusic Plugins Jan 28 01:30:42 music volumio[6214]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 28 01:30:42 music volumio[6214]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 28 01:30:42 music volumio[6214]: info: Loading plugins from folder /data/plugins/ Jan 28 01:30:42 music volumio[6214]: info: Loading plugin "system"... Jan 28 01:30:42 music volumio[6214]: info: Loading plugin "appearance"... Jan 28 01:30:42 music go-librespot[6230]: time="2026-01-28T01:30:42-05:00" level=debug msg="connected to ap-gue1.spotify.com:80" Jan 28 01:30:42 music go-librespot[6230]: time="2026-01-28T01:30:42-05:00" level=debug msg="completed keyexchange" Jan 28 01:30:42 music go-librespot[6230]: time="2026-01-28T01:30:42-05:00" level=debug msg="completed challenge" Jan 28 01:30:43 music go-librespot[6230]: time="2026-01-28T01:30:43-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 28 01:30:43 music go-librespot[6230]: time="2026-01-28T01:30:43-05:00" level=warning msg="failed to connect to AP ap-guc3.spotify.com:4070, retrying with a different AP" error="dial tcp 104.154.127.247:4070: connect: connection refused" Jan 28 01:30:43 music volumio[6214]: info: Loading plugin "network"... Jan 28 01:30:43 music volumio[6214]: info: Refreshing Cached IP Addresses Jan 28 01:30:43 music sudo[6252]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 28 01:30:43 music sudo[6252]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 01:30:43 music sudo[6254]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 28 01:30:43 music sudo[6254]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 01:30:43 music sudo[6252]: pam_unix(sudo:session): session closed for user root Jan 28 01:30:43 music sudo[6254]: pam_unix(sudo:session): session closed for user root Jan 28 01:30:43 music volumio[6214]: info: Loading plugin "services"... Jan 28 01:30:43 music go-librespot[6230]: time="2026-01-28T01:30:43-05:00" level=warning msg="failed to connect to AP ap-gew1.spotify.com:443, retrying with a different AP" error="dial tcp 104.199.65.9:443: connect: connection refused" Jan 28 01:30:43 music volumio[6214]: info: Loading plugin "alsa_controller"... Jan 28 01:30:43 music sudo[6263]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 28 01:30:43 music sudo[6263]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 01:30:43 music volumio[6214]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 01:30:43 music volumio[6214]: info: Loading plugin "wizard"... Jan 28 01:30:43 music volumio[6214]: info: Loading plugin "networkfs"... Jan 28 01:30:43 music go-librespot[6230]: time="2026-01-28T01:30:43-05:00" level=debug msg="connected to ap-gew4.spotify.com:80" Jan 28 01:30:43 music volumio[6214]: info: Starting Udev Watcher for removable devices Jan 28 01:30:43 music volumio[6214]: info: Ignoring mount for partition: boot Jan 28 01:30:43 music volumio[6214]: info: Ignoring mount for partition: volumio Jan 28 01:30:43 music volumio[6214]: info: Ignoring mount for partition: volumio_data Jan 28 01:30:43 music volumio[6214]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 01:30:43 music volumio[6214]: info: Loading plugin "volumio_command_line_client"... Jan 28 01:30:43 music volumio[6214]: info: Loading plugin "upnp"... Jan 28 01:30:43 music volumio[6214]: info: [1769581843855] Starting Upmpd Daemon Jan 28 01:30:43 music volumio[6214]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 01:30:43 music volumio[6214]: info: Loading plugin "my_music"... Jan 28 01:30:43 music volumio[6214]: info: Loading plugin "mpd"... Jan 28 01:30:43 music go-librespot[6230]: time="2026-01-28T01:30:43-05:00" level=debug msg="completed keyexchange" Jan 28 01:30:43 music go-librespot[6230]: time="2026-01-28T01:30:43-05:00" level=debug msg="completed challenge" Jan 28 01:30:44 music go-librespot[6230]: time="2026-01-28T01:30:44-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 28 01:30:44 music volumio[6214]: info: Loading plugin "upnp_browser"... Jan 28 01:30:44 music sudo[6263]: pam_unix(sudo:session): session closed for user root Jan 28 01:30:44 music volumio-remote-updater[1248]: [2026-01-28 01:30:44] [connect] Successful connection Jan 28 01:30:44 music go-librespot[6230]: time="2026-01-28T01:30:44-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Jan 28 01:30:44 music go-librespot[6230]: time="2026-01-28T01:30:44-05:00" level=debug msg="completed keyexchange" Jan 28 01:30:44 music go-librespot[6230]: time="2026-01-28T01:30:44-05:00" level=debug msg="completed challenge" Jan 28 01:30:44 music go-librespot[6230]: time="2026-01-28T01:30:44-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 28 01:30:45 music go-librespot[6230]: time="2026-01-28T01:30:45-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Jan 28 01:30:45 music go-librespot[6230]: time="2026-01-28T01:30:45-05:00" level=debug msg="completed keyexchange" Jan 28 01:30:45 music go-librespot[6230]: time="2026-01-28T01:30:45-05:00" level=debug msg="completed challenge" Jan 28 01:30:45 music go-librespot[6230]: time="2026-01-28T01:30:45-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 28 01:30:45 music go-librespot[6230]: time="2026-01-28T01:30:45-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 01:30:45 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 01:30:45 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 01:30:45 music volumio[6214]: info: Starting UPNP Browser Jan 28 01:30:45 music volumio[6214]: info: Loading plugin "alarm-clock"... Jan 28 01:30:45 music volumio[6214]: info: Loading plugin "airplay_emulation"... Jan 28 01:30:45 music volumio[6214]: info: Starting Shairport Sync Jan 28 01:30:45 music volumio[6214]: info: Loading plugin "last_100"... Jan 28 01:30:45 music volumio[6214]: info: Loading plugin "webradio"... Jan 28 01:30:46 music volumio[6214]: info: Loading plugin "i2s_dacs"... Jan 28 01:30:46 music volumio[6214]: info: I2S DAC not set, start Auto-detection Jan 28 01:30:46 music volumio[6214]: info: Loading plugin "volumiodiscovery"... Jan 28 01:30:46 music volumio[6214]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 28 01:30:46 music volumio[6214]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 01:30:46 music volumio[6214]: *** WARNING *** For more information see Jan 28 01:30:46 music volumio[6214]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 28 01:30:46 music volumio[6214]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 01:30:46 music volumio[6214]: *** WARNING *** For more information see Jan 28 01:30:46 music node[6214]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 28 01:30:46 music node[6214]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 01:30:46 music node[6214]: *** WARNING *** For more information see Jan 28 01:30:46 music node[6214]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 28 01:30:46 music node[6214]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 01:30:46 music node[6214]: *** WARNING *** For more information see Jan 28 01:30:46 music volumio[6214]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 28 01:30:46 music volumio[6214]: info: Discovery: Started advertising with name: music Jan 28 01:30:46 music volumio[6214]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 01:30:46 music volumio[6214]: info: Loading plugin "spop"... Jan 28 01:30:47 music volumio[6214]: info: Loading plugin "outputs"... Jan 28 01:30:47 music volumio[6214]: info: Loading plugin "albumart"... Jan 28 01:30:47 music volumio[6214]: info: Plugin example_plugin is not enabled Jan 28 01:30:47 music volumio[6214]: info: Loading plugin "inputs"... Jan 28 01:30:47 music volumio[6214]: info: Loading plugin "updater_comm"... Jan 28 01:30:47 music volumio[6214]: info: Plugin mpdemulation is not enabled Jan 28 01:30:47 music volumio[6214]: info: Loading plugin "rest_api"... Jan 28 01:30:47 music volumio[6214]: info: Loading plugin "websocket"... Jan 28 01:30:47 music volumio[6214]: info: Starting Socket.io Server version 1.7.4 Jan 28 01:30:47 music volumio[6214]: info: Loading i18n strings for locale en Jan 28 01:30:47 music volumio[6214]: Updating browse sources language Jan 28 01:30:47 music volumio[6214]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 01:30:47 music volumio[6214]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 01:30:47 music volumio[6214]: info: CoreCommandRouter::initPlayerControls Jan 28 01:30:47 music volumio[6214]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:30:47 music volumio[6214]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:30:47 music volumio[6214]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:30:47 music volumio[6214]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:30:47 music volumio[6214]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:30:47 music volumio[6214]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:30:47 music volumio[6214]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:30:47 music volumio[6214]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:30:47 music volumio[6214]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 01:30:47 music volumio[6214]: Express server listening on port 3000 Jan 28 01:30:47 music volumio[6214]: [Metrics] WebUI: 6s 584.26ms Jan 28 01:30:47 music volumio[6214]: info: CoreStateMachine::resetVolumioState Jan 28 01:30:47 music volumio[6214]: info: CoreStateMachine::getcurrentVolume Jan 28 01:30:47 music volumio[6214]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 01:30:47 music volumio[6214]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 01:30:47 music volumio[6214]: info: Volumio Network Manager: Network status updated: 1 Jan 28 01:30:47 music volumio-remote-updater[1248]: [2026-01-28 01:30:47] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1769581844 101 Jan 28 01:30:47 music volumio[6287]: Forking 3 albumart workers Jan 28 01:30:47 music volumio[6214]: 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 Jan 28 01:30:47 music volumio[6214]: info: VolumeController:: Volume=86 Mute =false Jan 28 01:30:47 music volumio[6214]: info: CoreStateMachine::pushState Jan 28 01:30:47 music volumio[6214]: info: CorePlayQueue::getTrack 0 Jan 28 01:30:47 music volumio[6214]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 01:30:47 music volumio[6214]: info: CoreCommandRouter::volumioPushState Jan 28 01:30:47 music volumio[6214]: info: CoreStateMachine::updateTrackBlock Jan 28 01:30:47 music volumio[6214]: info: CorePlayQueue::getTrackBlock Jan 28 01:30:47 music volumio[6214]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 01:30:47 music volumio[6214]: info: Reloading queue from file Jan 28 01:30:47 music volumio[6214]: info: Setting Device type: Raspberry PI Jan 28 01:30:47 music volumio[6214]: info: CoreStateMachine::setRepeat null single undefined Jan 28 01:30:47 music volumio[6214]: info: CoreStateMachine::pushState Jan 28 01:30:47 music volumio[6214]: info: CorePlayQueue::getTrack 0 Jan 28 01:30:47 music volumio[6214]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 01:30:47 music volumio[6214]: info: CoreCommandRouter::volumioPushState Jan 28 01:30:47 music volumio[6214]: info: CoreStateMachine::setRandom null Jan 28 01:30:47 music volumio[6214]: info: CoreStateMachine::pushState Jan 28 01:30:47 music volumio[6214]: info: CorePlayQueue::getTrack 0 Jan 28 01:30:47 music volumio[6214]: info: CoreCommandRouter::volumioPushState Jan 28 01:30:48 music volumio[6214]: info: VolumeController:: Volume=86 Mute =false Jan 28 01:30:48 music volumio[6214]: info: CoreStateMachine::pushState Jan 28 01:30:48 music volumio[6214]: info: CorePlayQueue::getTrack 0 Jan 28 01:30:48 music volumio[6214]: info: CoreCommandRouter::volumioPushState Jan 28 01:30:48 music volumio[6214]: info: Completed loading Core Plugins Jan 28 01:30:48 music volumio[6214]: info: Preparing to generate the ALSA configuration file Jan 28 01:30:48 music volumio[6214]: info: Discovery: adding 4a29b7a7-c637-4926-a2bd-fb4e2f55145e Jan 28 01:30:48 music volumio[6214]: info: Discovery: Found device music Jan 28 01:30:48 music volumio[6214]: info: CoreCommandRouter::volumioGetState Jan 28 01:30:48 music volumio[6214]: info: CorePlayQueue::getTrack 0 Jan 28 01:30:48 music volumio[6214]: info: Discovery: this is already registered, 4a29b7a7-c637-4926-a2bd-fb4e2f55145e Jan 28 01:30:48 music volumio[6214]: info: Discovery: Found device music Jan 28 01:30:48 music volumio[6214]: info: CoreCommandRouter::volumioGetState Jan 28 01:30:48 music volumio[6214]: info: CorePlayQueue::getTrack 0 Jan 28 01:30:48 music volumio[6214]: info: Asound.conf file unchanged, so no further update is needed Jan 28 01:30:48 music volumio[6214]: info: Output device has changed, restarting MPD Jan 28 01:30:48 music volumio[6214]: info: Output device has changed, restarting Shairport Sync Jan 28 01:30:48 music volumio[6214]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:30:48 music volumio[6214]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 01:30:48 music sudo[6343]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 28 01:30:48 music sudo[6343]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 01:30:48 music sudo[6343]: pam_unix(sudo:session): session closed for user root Jan 28 01:30:48 music sudo[6345]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 28 01:30:48 music volumio[6214]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 01:30:48 music sudo[6345]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 01:30:48 music volumio[6214]: info: ___________ START PLUGINS ___________ Jan 28 01:30:48 music volumio[6214]: info: ControllerMpd::onStart: Initializing MPD Jan 28 01:30:48 music volumio[6214]: info: Creating MPD Configuration file Jan 28 01:30:48 music volumio[6214]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 01:30:48 music volumio[6214]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 01:30:48 music volumio[6214]: info: [1769581848277] CoreMusicLibrary::Adding element Media Servers Jan 28 01:30:48 music volumio[6214]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 01:30:48 music systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 28 01:30:48 music volumio[6214]: info: UPNP Browser: Client initialized successfully Jan 28 01:30:48 music sudo[6352]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 28 01:30:48 music sudo[6352]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 01:30:48 music sudo[6352]: pam_unix(sudo:session): session closed for user root Jan 28 01:30:48 music sudo[6354]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 28 01:30:48 music sudo[6354]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 01:30:48 music systemd[1]: mpd.service: Deactivated successfully. Jan 28 01:30:48 music systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 28 01:30:48 music systemd[1]: mpd.service: Consumed 4.167s CPU time. Jan 28 01:30:48 music systemd[1]: mpd.socket: Deactivated successfully. Jan 28 01:30:48 music systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 28 01:30:48 music systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 28 01:30:48 music volumio[6214]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:30:48 music volumio[6214]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 01:30:48 music volumio[6214]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 01:30:48 music volumio[6214]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:30:48 music volumio[6214]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 01:30:48 music systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 28 01:30:48 music systemd[1]: Starting mpd.service - Music Player Daemon... Jan 28 01:30:48 music volumio[6214]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 01:30:48 music systemd[1]: mpd.service: Deactivated successfully. Jan 28 01:30:48 music systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 28 01:30:48 music volumio[6214]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 01:30:48 music volumio[6214]: info: [1769581848524] CoreMusicLibrary::Adding element Last_100 Jan 28 01:30:48 music volumio[6214]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 01:30:48 music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Jan 28 01:30:48 music systemd[1]: mpd.socket: Deactivated successfully. Jan 28 01:30:48 music volumio[6214]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 01:30:48 music volumio[6214]: info: [1769581848532] CoreMusicLibrary::Adding element Webradio Jan 28 01:30:48 music volumio[6214]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 01:30:48 music systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 28 01:30:48 music systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 28 01:30:48 music systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 28 01:30:48 music volumio[6214]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 01:30:48 music volumio[6214]: info: Initializing BBC Radios Jan 28 01:30:48 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 01:30:48 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 01:30:48 music go-librespot[6369]: go-librespot daemon starting... Jan 28 01:30:48 music systemd[1]: Starting mpd.service - Music Player Daemon... Jan 28 01:30:48 music go-librespot[6373]: time="2026-01-28T01:30:48-05:00" level=info msg="running go-librespot 0.6.2" Jan 28 01:30:48 music go-librespot[6373]: time="2026-01-28T01:30:48-05:00" level=debug msg="app state loaded" Jan 28 01:30:48 music go-librespot[6373]: time="2026-01-28T01:30:48-05:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 01:30:48 music volumio[6214]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 01:30:48 music volumio[6214]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 01:30:48 music volumio[6214]: info: Creating Spotify config file Jan 28 01:30:48 music volumio[6214]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:30:48 music sudo[6372]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 28 01:30:48 music sudo[6372]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 28 01:30:48 music sudo[6372]: pam_unix(sudo:session): session closed for user root Jan 28 01:30:49 music go-librespot[6373]: time="2026-01-28T01:30:49-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew1.spotify.com:80]" Jan 28 01:30:49 music go-librespot[6373]: time="2026-01-28T01:30:49-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 28 01:30:49 music go-librespot[6373]: time="2026-01-28T01:30:49-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 28 01:30:49 music go-librespot[6373]: time="2026-01-28T01:30:49-05:00" level=info msg="zeroconf server listening on port 38287" Jan 28 01:30:49 music go-librespot[6373]: time="2026-01-28T01:30:49-05:00" level=debug msg="obtained new client token: AABuE212MC/XnUeq9xk0Ad9MP3LR37Jfn9a/ugj4W1pbcWMahU1Eq8zymEJWXtauze0EsdJBCFO1kB7zLgo2KnBkc5rAJcIHGoYU+ZemSlH/24c35aKh02x0RTIJ8016juZe3vTbQNRX4wdDu5Ei30mBQYZhYRICf60Br8+sBxWzJXcgL7XOW4IpZExPwt/WtIjsA6Ud45ghey4xX+NAgrOgFehb9xZBWYLHbbIOhGMpxo8XXf1M+X0=" Jan 28 01:30:49 music go-librespot[6373]: time="2026-01-28T01:30:49-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Jan 28 01:30:49 music volumio[6214]: info: Volumio Calling Home Jan 28 01:30:49 music go-librespot[6373]: time="2026-01-28T01:30:49-05:00" level=debug msg="completed keyexchange" Jan 28 01:30:49 music go-librespot[6373]: time="2026-01-28T01:30:49-05:00" level=debug msg="completed challenge" Jan 28 01:30:49 music go-librespot[6373]: time="2026-01-28T01:30:49-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 28 01:30:49 music volumio[6304]: Starting albumart workers Jan 28 01:30:50 music volumio[6305]: Starting albumart workers Jan 28 01:30:50 music volumio[6214]: info: MPD Permissions set Jan 28 01:30:50 music volumio[6214]: info: MPD Permissions set Jan 28 01:30:50 music go-librespot[6373]: time="2026-01-28T01:30:50-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Jan 28 01:30:50 music volumio[6303]: Starting albumart workers Jan 28 01:30:50 music volumio[6214]: info: Volumio called home Jan 28 01:30:50 music volumio[6214]: info: Spotify config file written Jan 28 01:30:50 music go-librespot[6373]: time="2026-01-28T01:30:50-05:00" level=debug msg="completed keyexchange" Jan 28 01:30:50 music go-librespot[6373]: time="2026-01-28T01:30:50-05:00" level=debug msg="completed challenge" Jan 28 01:30:50 music sudo[6398]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 28 01:30:50 music go-librespot[6373]: time="2026-01-28T01:30:50-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 28 01:30:50 music sudo[6398]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 01:30:50 music systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Jan 28 01:30:50 music systemd[1]: go-librespot-daemon.service: Deactivated successfully. Jan 28 01:30:50 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 01:30:50 music volumio[6214]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Jan 28 01:30:50 music volumio[6214]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:30:50 music volumio[6214]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:30:50 music volumio[6214]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:30:50 music volumio[6214]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:30:50 music volumio[6214]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:30:50 music volumio[6214]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:30:50 music volumio[6214]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:30:50 music volumio[6214]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:30:50 music volumio[6214]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 01:30:50 music volumio[6214]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:30:50 music volumio[6214]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:30:50 music volumio[6214]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:30:50 music volumio[6214]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:30:50 music volumio[6214]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:30:50 music volumio[6214]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:30:50 music volumio[6214]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:30:50 music volumio[6214]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:30:50 music volumio[6214]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:30:50 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 01:30:50 music go-librespot[6400]: go-librespot daemon starting... Jan 28 01:30:50 music volumio[6214]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 01:30:50 music sudo[6398]: pam_unix(sudo:session): session closed for user root Jan 28 01:30:50 music volumio[6214]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:30:50 music volumio[6214]: info: No need to fix Spotify hosts Jan 28 01:30:50 music go-librespot[6411]: time="2026-01-28T01:30:50-05:00" level=info msg="running go-librespot 0.6.2" Jan 28 01:30:50 music go-librespot[6411]: time="2026-01-28T01:30:50-05:00" level=debug msg="app state loaded" Jan 28 01:30:50 music go-librespot[6411]: time="2026-01-28T01:30:50-05:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 01:30:50 music go-librespot[6411]: time="2026-01-28T01:30:50-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 01:30:50 music go-librespot[6411]: time="2026-01-28T01:30:50-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 01:30:51 music go-librespot[6411]: time="2026-01-28T01:30:50-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 01:30:51 music go-librespot[6411]: time="2026-01-28T01:30:51-05:00" level=info msg="zeroconf server listening on port 33205" Jan 28 01:30:51 music go-librespot[6411]: time="2026-01-28T01:30:51-05:00" level=debug msg="obtained new client token: AAA9bxMHIHEKQeuZ+L2k2cuTL4DLvfhYv4BNnsdytYfnX+dBu+EKnVYq3DSv//S2CIt+NB/Q6y65566dmiKJS4LgKQGqWFLnR1f2UvDSUgNshhGJN37GUZgJWTfetbfRv7DbMCesD4tbaIQ6b1h1c1DUsrMNGzS7gv5uO4M8B8PyUYW9UVa4aVHDoCJ9WmKvnKmnkIfESO1U6vG/kxdBS+aXR0OEvKAUojLrNTsRDdAXxESVCcPd" Jan 28 01:30:51 music volumio[6214]: info: An error occurred while refreshing Spotify Token Error: Bad Request Jan 28 01:30:51 music volumio[6214]: info: Starting Shairport Sync Jan 28 01:30:51 music volumio[6214]: info: Starting Shairport Sync Jan 28 01:30:51 music go-librespot[6411]: time="2026-01-28T01:30:51-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Jan 28 01:30:51 music volumio[6214]: info: Starting Shairport Sync Jan 28 01:30:51 music sudo[6437]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 01:30:51 music sudo[6437]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 01:30:51 music volumio[6214]: info: CoreCommandRouter::volumioGetState Jan 28 01:30:51 music volumio[6214]: info: CorePlayQueue::getTrack 0 Jan 28 01:30:51 music sudo[6435]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 01:30:51 music sudo[6435]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 01:30:51 music go-librespot[6411]: time="2026-01-28T01:30:51-05:00" level=debug msg="completed keyexchange" Jan 28 01:30:51 music go-librespot[6411]: time="2026-01-28T01:30:51-05:00" level=debug msg="completed challenge" Jan 28 01:30:51 music sudo[6439]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 01:30:51 music sudo[6439]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 01:30:51 music systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 28 01:30:51 music systemd[1]: shairport-sync.service: Deactivated successfully. Jan 28 01:30:51 music systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 01:30:51 music systemd[1]: shairport-sync.service: Consumed 1.863s CPU time. Jan 28 01:30:51 music go-librespot[6411]: time="2026-01-28T01:30:51-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 28 01:30:51 music volumio[6214]: info: Listing playlists Jan 28 01:30:51 music volumio[6214]: info: Listing playlists Jan 28 01:30:51 music volumio[6214]: info: CoreCommandRouter::volumioGetState Jan 28 01:30:51 music volumio[6214]: info: CorePlayQueue::getTrack 0 Jan 28 01:30:51 music systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 01:30:51 music sudo[6435]: pam_unix(sudo:session): session closed for user root Jan 28 01:30:51 music systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 28 01:30:51 music systemd[1]: shairport-sync.service: Deactivated successfully. Jan 28 01:30:51 music systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 01:30:51 music volumio[6214]: info: Shairport-Sync Started Jan 28 01:30:51 music systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 01:30:51 music volumio[6214]: Error adding Membership: Error: addMembership EINVAL Jan 28 01:30:51 music sudo[6437]: pam_unix(sudo:session): session closed for user root Jan 28 01:30:51 music volumio[6214]: info: Shairport-Sync Started Jan 28 01:30:51 music sudo[6439]: pam_unix(sudo:session): session closed for user root Jan 28 01:30:51 music volumio[6214]: info: Shairport-Sync Started Jan 28 01:30:52 music go-librespot[6411]: time="2026-01-28T01:30:52-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Jan 28 01:30:52 music go-librespot[6411]: time="2026-01-28T01:30:52-05:00" level=debug msg="completed keyexchange" Jan 28 01:30:52 music go-librespot[6411]: time="2026-01-28T01:30:52-05:00" level=debug msg="completed challenge" Jan 28 01:30:52 music go-librespot[6411]: time="2026-01-28T01:30:52-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 28 01:30:52 music go-librespot[6411]: time="2026-01-28T01:30:52-05:00" level=debug msg="connected to ap-gue1.spotify.com:80" Jan 28 01:30:52 music go-librespot[6411]: time="2026-01-28T01:30:52-05:00" level=debug msg="completed keyexchange" Jan 28 01:30:52 music go-librespot[6411]: time="2026-01-28T01:30:52-05:00" level=debug msg="completed challenge" Jan 28 01:30:52 music go-librespot[6411]: time="2026-01-28T01:30:52-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 28 01:30:53 music mpd[6392]: 2026-01-28T01:30:53 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 28 01:30:53 music systemd[1]: Started mpd.service - Music Player Daemon. Jan 28 01:30:53 music sudo[6345]: pam_unix(sudo:session): session closed for user root Jan 28 01:30:53 music sudo[6354]: pam_unix(sudo:session): session closed for user root Jan 28 01:30:53 music volumio[6214]: info: Completed starting Core Plugins Jan 28 01:30:53 music volumio[6214]: info: ------------------------------------------- Jan 28 01:30:53 music volumio[6214]: info: ----- MyVolumio plugins startup ---- Jan 28 01:30:53 music volumio[6214]: info: ------------------------------------------- Jan 28 01:30:53 music volumio[6214]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 28 01:30:53 music volumio[6214]: error: MPD error: The expression evaluated to a falsy value: Jan 28 01:30:53 music volumio[6214]: assert.ok(self.idling) Jan 28 01:30:53 music volumio[6214]: error: The expression evaluated to a falsy value: Jan 28 01:30:53 music volumio[6214]: assert.ok(self.idling) Jan 28 01:30:53 music volumio[6214]: info: MPD running with PID6392 Jan 28 01:30:53 music volumio[6214]: ,establishing connection Jan 28 01:30:53 music volumio[6214]: error: updateQueue error: null Jan 28 01:30:53 music volumio[6214]: error: updateQueue error: null Jan 28 01:30:53 music go-librespot[6411]: time="2026-01-28T01:30:53-05:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 01:30:53 music sudo[6486]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 28 01:30:53 music sudo[6486]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 01:30:53 music sudo[6488]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 28 01:30:53 music sudo[6486]: pam_unix(sudo:session): session closed for user root Jan 28 01:30:53 music sudo[6488]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 01:30:53 music sudo[6488]: pam_unix(sudo:session): session closed for user root Jan 28 01:30:53 music go-librespot[6411]: time="2026-01-28T01:30:53-05:00" level=debug msg="completed keyexchange" Jan 28 01:30:53 music go-librespot[6411]: time="2026-01-28T01:30:53-05:00" level=debug msg="completed challenge" Jan 28 01:30:53 music sudo[6491]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 28 01:30:53 music sudo[6491]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 01:30:53 music sudo[6491]: pam_unix(sudo:session): session closed for user root Jan 28 01:30:53 music volumio[6214]: info: Upmpdcli Daemon Started Jan 28 01:30:54 music go-librespot[6411]: time="2026-01-28T01:30:54-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 28 01:30:54 music volumio[6214]: info: go-librespot daemon successfully initialized Jan 28 01:30:54 music go-librespot[6411]: time="2026-01-28T01:30:54-05:00" level=warning msg="failed to connect to AP ap-gew1.spotify.com:443, retrying with a different AP" error="dial tcp: lookup ap-gew1.spotify.com: device or resource busy" Jan 28 01:30:54 music go-librespot[6411]: time="2026-01-28T01:30:54-05:00" level=debug msg="connected to ap-gew4.spotify.com:80" Jan 28 01:30:55 music go-librespot[6411]: time="2026-01-28T01:30:55-05:00" level=debug msg="completed keyexchange" Jan 28 01:30:55 music go-librespot[6411]: time="2026-01-28T01:30:55-05:00" level=debug msg="completed challenge" Jan 28 01:30:55 music go-librespot[6411]: time="2026-01-28T01:30:55-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 28 01:30:55 music go-librespot[6411]: time="2026-01-28T01:30:55-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Jan 28 01:30:55 music go-librespot[6411]: time="2026-01-28T01:30:55-05:00" level=debug msg="completed keyexchange" Jan 28 01:30:55 music go-librespot[6411]: time="2026-01-28T01:30:55-05:00" level=debug msg="completed challenge" Jan 28 01:30:55 music go-librespot[6411]: time="2026-01-28T01:30:55-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 28 01:30:55 music go-librespot[6411]: time="2026-01-28T01:30:55-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 01:30:55 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 01:30:55 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 01:30:56 music sudo[6495]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Jan 28 01:30:56 music sudo[6495]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 01:30:56 music sudo[6497]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Jan 28 01:30:56 music sudo[6497]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 01:30:56 music systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Jan 28 01:30:56 music systemd[1]: mpd_monitor.service: Deactivated successfully. Jan 28 01:30:56 music systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Jan 28 01:30:56 music systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Jan 28 01:30:56 music sudo[6495]: pam_unix(sudo:session): session closed for user root Jan 28 01:30:56 music sudo[6497]: pam_unix(sudo:session): session closed for user root Jan 28 01:30:56 music volumio[6214]: info: Successfully started MPD Monitor Jan 28 01:30:56 music volumio[6214]: info: Successfully started MPD Monitor Jan 28 01:30:56 music mpd_monitor.sh[6500]: MPD Monitor Service: Starting MPD Monitor Service Jan 28 01:30:57 music volumio[6214]: info: Initializing connection to go-librespot Websocket Jan 28 01:30:57 music volumio[6214]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 01:30:58 music volumio[6214]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 28 01:30:59 music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Jan 28 01:30:59 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 01:30:59 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 01:30:59 music go-librespot[6504]: go-librespot daemon starting... Jan 28 01:30:59 music go-librespot[6505]: time="2026-01-28T01:30:59-05:00" level=info msg="running go-librespot 0.6.2" Jan 28 01:30:59 music go-librespot[6505]: time="2026-01-28T01:30:59-05:00" level=debug msg="app state loaded" Jan 28 01:30:59 music go-librespot[6505]: time="2026-01-28T01:30:59-05:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 01:30:59 music go-librespot[6505]: time="2026-01-28T01:30:59-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 01:30:59 music go-librespot[6505]: time="2026-01-28T01:30:59-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 01:30:59 music go-librespot[6505]: time="2026-01-28T01:30:59-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 01:30:59 music go-librespot[6505]: time="2026-01-28T01:30:59-05:00" level=info msg="zeroconf server listening on port 33831" Jan 28 01:30:59 music go-librespot[6505]: time="2026-01-28T01:30:59-05:00" level=debug msg="obtained new client token: AACHpNygnUiK6e6/zvbNklH9OYImd+EeFEYtiKrtYgkIovrHZ32vnhSOFyDsDHhTtvwGcHGchP4w/sEFc4sGZDHcy7czbFJ2dFjH038vL7vd9VmAp2zeGtPdvOI6ERZXwZCxIZCOS+/DfNpckjKXHCnN1Q6wHwh/G/TpaDHenxaOU9OeP2ZQX5OnK1Bb8463sIBzKfA/shw9WlOyGd71TJwQaWOBBAulp2ghWPvaOCqfS9dzXE7nOmE=" Jan 28 01:30:59 music go-librespot[6505]: time="2026-01-28T01:30:59-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Jan 28 01:30:59 music go-librespot[6505]: time="2026-01-28T01:30:59-05:00" level=debug msg="completed keyexchange" Jan 28 01:30:59 music go-librespot[6505]: time="2026-01-28T01:30:59-05:00" level=debug msg="completed challenge" Jan 28 01:30:59 music go-librespot[6505]: time="2026-01-28T01:30:59-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 28 01:31:00 music volumio[6214]: info: Initializing connection to go-librespot Websocket Jan 28 01:31:00 music go-librespot[6505]: time="2026-01-28T01:31:00-05:00" level=debug msg="new websocket client" Jan 28 01:31:00 music volumio[6214]: info: Connection to go-librespot Websocket established Jan 28 01:31:00 music go-librespot[6505]: time="2026-01-28T01:31:00-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Jan 28 01:31:00 music go-librespot[6505]: time="2026-01-28T01:31:00-05:00" level=debug msg="completed keyexchange" Jan 28 01:31:00 music go-librespot[6505]: time="2026-01-28T01:31:00-05:00" level=debug msg="completed challenge" Jan 28 01:31:00 music go-librespot[6505]: time="2026-01-28T01:31:00-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 28 01:31:00 music volumio[6214]: info: CoreCommandRouter::volumioGetState Jan 28 01:31:00 music volumio[6214]: info: CorePlayQueue::getTrack 0 Jan 28 01:31:01 music go-librespot[6505]: time="2026-01-28T01:31:01-05:00" level=debug msg="connected to ap-gue1.spotify.com:80" Jan 28 01:31:01 music go-librespot[6505]: time="2026-01-28T01:31:01-05:00" level=debug msg="completed keyexchange" Jan 28 01:31:01 music go-librespot[6505]: time="2026-01-28T01:31:01-05:00" level=debug msg="completed challenge" Jan 28 01:31:01 music go-librespot[6505]: time="2026-01-28T01:31:01-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 28 01:31:01 music volumio[6214]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 28 01:31:01 music volumio[6214]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 28 01:31:01 music volumio[6214]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 28 01:31:01 music volumio[6214]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jan 28 01:31:01 music volumio[6214]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 28 01:31:01 music volumio[6214]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 28 01:31:01 music volumio[6214]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 28 01:31:01 music volumio[6214]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 28 01:31:01 music volumio[6214]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 28 01:31:01 music volumio[6214]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 28 01:31:01 music volumio[6214]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jan 28 01:31:01 music volumio[6214]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 28 01:31:01 music volumio[6214]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 28 01:31:01 music volumio[6214]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 28 01:31:01 music volumio[6214]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jan 28 01:31:01 music volumio[6214]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 28 01:31:01 music volumio[6214]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 28 01:31:01 music volumio[6214]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 28 01:31:01 music volumio[6214]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 28 01:31:01 music volumio[6214]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 28 01:31:01 music volumio[6214]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 28 01:31:01 music volumio[6214]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jan 28 01:31:01 music volumio[6214]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 28 01:31:01 music volumio[6214]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jan 28 01:31:01 music volumio[6214]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 28 01:31:01 music volumio[6214]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 28 01:31:01 music volumio[6214]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 28 01:31:01 music volumio[6214]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 28 01:31:01 music volumio[6214]: info: Adding plugin bluetooth to MyMusic Plugins Jan 28 01:31:01 music volumio[6214]: info: Adding plugin multiroom to MyMusic Plugins Jan 28 01:31:01 music volumio[6214]: info: Adding plugin metavolumio to MyMusic Plugins Jan 28 01:31:01 music volumio[6214]: info: Adding plugin cd_controller to MyMusic Plugins Jan 28 01:31:01 music volumio[6214]: info: Adding plugin qobuzconnect to MyMusic Plugins Jan 28 01:31:01 music volumio[6214]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 28 01:31:01 music volumio[6214]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 28 01:31:01 music volumio[6214]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 28 01:31:01 music go-librespot[6505]: time="2026-01-28T01:31:01-05:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 28 01:31:01 music go-librespot[6505]: time="2026-01-28T01:31:01-05:00" level=debug msg="completed keyexchange" Jan 28 01:31:01 music go-librespot[6505]: time="2026-01-28T01:31:01-05:00" level=debug msg="completed challenge" Jan 28 01:31:01 music go-librespot[6505]: time="2026-01-28T01:31:01-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 28 01:31:02 music go-librespot[6505]: time="2026-01-28T01:31:02-05:00" level=debug msg="connected to ap-gew1.spotify.com:443" Jan 28 01:31:02 music go-librespot[6505]: time="2026-01-28T01:31:02-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.3.63:57644->104.199.65.9:443: read: connection reset by peer" Jan 28 01:31:02 music volumio[6214]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 28 01:31:02 music volumio[6214]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 28 01:31:02 music volumio[6214]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 01:31:02 music volumio[6214]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 01:31:02 music volumio[6214]: info: Starting MyVolumio Remote Streaming Endpoints Jan 28 01:31:02 music volumio[6214]: info: MyVolumio login type: Token Jan 28 01:31:02 music volumio[6214]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 28 01:31:02 music volumio[6214]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 28 01:31:03 music go-librespot[6505]: time="2026-01-28T01:31:03-05:00" level=warning msg="failed to connect to AP ap-gew4.spotify.com:80, retrying with a different AP" error="dial tcp 34.158.1.133:80: connect: connection refused" Jan 28 01:31:03 music go-librespot[6505]: time="2026-01-28T01:31:03-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Jan 28 01:31:03 music go-librespot[6505]: time="2026-01-28T01:31:03-05:00" level=debug msg="completed keyexchange" Jan 28 01:31:03 music go-librespot[6505]: time="2026-01-28T01:31:03-05:00" level=debug msg="completed challenge" Jan 28 01:31:03 music go-librespot[6505]: time="2026-01-28T01:31:03-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 28 01:31:03 music go-librespot[6505]: time="2026-01-28T01:31:03-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 01:31:03 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 01:31:03 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 01:31:03 music volumio[6214]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 28 01:31:03 music volumio[6214]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 28 01:31:03 music volumio[6214]: info: Streaming services startup Jan 28 01:31:03 music volumio[6214]: info: Starting Streaming Daemon Jan 28 01:31:03 music sudo[6515]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 28 01:31:03 music sudo[6515]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 01:31:03 music volumio[6214]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 28 01:31:03 music sudo[6515]: pam_unix(sudo:session): session closed for user root Jan 28 01:31:03 music volumio[6214]: info: Getting Spotify volume Jan 28 01:31:03 music volumio[6214]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 01:31:03 music volumio[6214]: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 01:31:03 music volumio[6214]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Jan 28 01:31:03 music volumio[6214]: errno: -111, Jan 28 01:31:03 music volumio[6214]: code: 'ECONNREFUSED', Jan 28 01:31:03 music volumio[6214]: syscall: 'connect', Jan 28 01:31:03 music volumio[6214]: address: '127.0.0.1', Jan 28 01:31:03 music volumio[6214]: port: 9879, Jan 28 01:31:03 music volumio[6214]: response: undefined Jan 28 01:31:03 music volumio[6214]: } Jan 28 01:31:03 music volumio[6214]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 01:31:04 music sudo[6550]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-28 01:30' Jan 28 01:31:04 music sudo[6550]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 01:31:04 music sudo[6550]: pam_unix(sudo:session): session closed for user root Jan 28 01:31:04 music volumio-remote-updater[1248]: [2026-01-28 01:31:04] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Jan 28 01:31:04 music volumio-remote-updater[1248]: [2026-01-28 01:31:04] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Jan 28 01:31:04 music systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 28 01:31:04 music systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 28 01:31:04 music systemd[1]: volumio.service: Consumed 26.464s CPU time. Jan 28 01:31:04 music systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 28 01:31:04 music systemd[1]: dynamicswap.service: Deactivated successfully. Jan 28 01:31:05 music systemd[1]: volumio.service: Scheduled restart job, restart counter is at 32207. Jan 28 01:31:05 music systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 28 01:31:05 music systemd[1]: Stopped volumio.service - Volumio Backend Module. Jan 28 01:31:05 music systemd[1]: volumio.service: Consumed 26.464s CPU time. Jan 28 01:31:05 music systemd[1]: Started volumio.service - Volumio Backend Module. Jan 28 01:31:05 music systemd[1]: dynamicswap.service: Deactivated successfully. Jan 28 01:31:06 music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Jan 28 01:31:06 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 01:31:06 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 01:31:06 music go-librespot[6584]: go-librespot daemon starting... Jan 28 01:31:06 music go-librespot[6585]: time="2026-01-28T01:31:06-05:00" level=info msg="running go-librespot 0.6.2" Jan 28 01:31:06 music go-librespot[6585]: time="2026-01-28T01:31:06-05:00" level=debug msg="app state loaded" Jan 28 01:31:06 music go-librespot[6585]: time="2026-01-28T01:31:06-05:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 01:31:06 music go-librespot[6585]: time="2026-01-28T01:31:06-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 01:31:06 music go-librespot[6585]: time="2026-01-28T01:31:06-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 01:31:06 music go-librespot[6585]: time="2026-01-28T01:31:06-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 01:31:06 music go-librespot[6585]: time="2026-01-28T01:31:06-05:00" level=info msg="zeroconf server listening on port 41495" Jan 28 01:31:07 music go-librespot[6585]: time="2026-01-28T01:31:07-05:00" level=debug msg="obtained new client token: AABIZhrtpR+cX608QDz0m3MMmaoqey6qBBYbQJfGA61/tl4aCd7gkGi443GMEqvLEIF0H8th7tNuh7djh9+gLeH7VoukmdeBqBM35RUMZUhdAYaVPWeCYIyxQzLq11YQsyMh0tywGF7262ze40P9zQylZbH9hjFrtS6X24o8f14pocD9do+tk4oRQzZv5OZDTokMy3tfDA1CNhTXm9KrNMxdDEDvGZ2WBxEBwkiziuwzIRt9TGU2" Jan 28 01:31:07 music volumio[6569]: info: ------------------------------------------- Jan 28 01:31:07 music volumio[6569]: info: ----- Volumio3 ---- Jan 28 01:31:07 music volumio[6569]: info: ------------------------------------------- Jan 28 01:31:07 music volumio[6569]: info: ----- System startup ---- Jan 28 01:31:07 music volumio[6569]: info: ------------------------------------------- Jan 28 01:31:07 music go-librespot[6585]: time="2026-01-28T01:31:07-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Jan 28 01:31:07 music go-librespot[6585]: time="2026-01-28T01:31:07-05:00" level=debug msg="completed keyexchange" Jan 28 01:31:07 music go-librespot[6585]: time="2026-01-28T01:31:07-05:00" level=debug msg="completed challenge" Jan 28 01:31:07 music go-librespot[6585]: time="2026-01-28T01:31:07-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 28 01:31:07 music go-librespot[6585]: time="2026-01-28T01:31:07-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Jan 28 01:31:07 music volumio[6569]: info: MYVOLUMIO Environment detected Jan 28 01:31:07 music go-librespot[6585]: time="2026-01-28T01:31:07-05:00" level=debug msg="completed keyexchange" Jan 28 01:31:07 music go-librespot[6585]: time="2026-01-28T01:31:07-05:00" level=debug msg="completed challenge" Jan 28 01:31:08 music volumio[6569]: info: Plugin folders cleanup Jan 28 01:31:08 music volumio[6569]: info: Scanning into folder /volumio/app/plugins/ Jan 28 01:31:08 music volumio[6569]: info: Scanning category audio_interface Jan 28 01:31:08 music volumio[6569]: info: Scanning category miscellanea Jan 28 01:31:08 music volumio[6569]: info: Scanning category music_service Jan 28 01:31:08 music volumio[6569]: info: Scanning category plugins.json Jan 28 01:31:08 music volumio[6569]: info: Scanning category system_controller Jan 28 01:31:08 music volumio[6569]: info: Scanning category user_interface Jan 28 01:31:08 music volumio[6569]: info: Scanning into folder /data/plugins/ Jan 28 01:31:08 music volumio[6569]: info: Scanning category music_service Jan 28 01:31:08 music volumio[6569]: info: Plugin folders cleanup completed Jan 28 01:31:08 music volumio[6569]: info: ------------------------------------------- Jan 28 01:31:08 music go-librespot[6585]: time="2026-01-28T01:31:08-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 28 01:31:08 music volumio[6569]: info: ----- Core plugins startup ---- Jan 28 01:31:08 music volumio[6569]: info: ------------------------------------------- Jan 28 01:31:08 music volumio[6569]: info: Loading plugins from folder /volumio/app/plugins/ Jan 28 01:31:08 music volumio[6569]: info: Adding plugin upnp to MyMusic Plugins Jan 28 01:31:08 music volumio[6569]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 28 01:31:08 music volumio[6569]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 28 01:31:08 music volumio[6569]: info: Loading plugins from folder /data/plugins/ Jan 28 01:31:08 music volumio[6569]: info: Loading plugin "system"... Jan 28 01:31:08 music volumio[6569]: info: Loading plugin "appearance"... Jan 28 01:31:08 music go-librespot[6585]: time="2026-01-28T01:31:08-05:00" level=debug msg="connected to ap-gue1.spotify.com:80" Jan 28 01:31:08 music go-librespot[6585]: time="2026-01-28T01:31:08-05:00" level=debug msg="completed keyexchange" Jan 28 01:31:08 music go-librespot[6585]: time="2026-01-28T01:31:08-05:00" level=debug msg="completed challenge" Jan 28 01:31:08 music go-librespot[6585]: time="2026-01-28T01:31:08-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 28 01:31:09 music volumio[6569]: info: Loading plugin "network"... Jan 28 01:31:09 music volumio[6569]: info: Refreshing Cached IP Addresses Jan 28 01:31:09 music sudo[6607]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 28 01:31:09 music sudo[6607]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 01:31:09 music sudo[6609]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 28 01:31:09 music sudo[6609]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 01:31:09 music sudo[6607]: pam_unix(sudo:session): session closed for user root Jan 28 01:31:09 music sudo[6609]: pam_unix(sudo:session): session closed for user root Jan 28 01:31:09 music volumio[6569]: info: Loading plugin "services"... Jan 28 01:31:09 music volumio[6569]: info: Loading plugin "alsa_controller"... Jan 28 01:31:09 music sudo[6618]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 28 01:31:09 music sudo[6618]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 01:31:09 music volumio[6569]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 01:31:09 music volumio[6569]: info: Loading plugin "wizard"... Jan 28 01:31:09 music volumio[6569]: info: Loading plugin "networkfs"... Jan 28 01:31:09 music volumio[6569]: info: Starting Udev Watcher for removable devices Jan 28 01:31:09 music volumio[6569]: info: Ignoring mount for partition: boot Jan 28 01:31:09 music volumio[6569]: info: Ignoring mount for partition: volumio Jan 28 01:31:09 music volumio[6569]: info: Ignoring mount for partition: volumio_data Jan 28 01:31:09 music volumio[6569]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 01:31:09 music volumio[6569]: info: Loading plugin "volumio_command_line_client"... Jan 28 01:31:09 music volumio[6569]: info: Loading plugin "upnp"... Jan 28 01:31:09 music volumio[6569]: info: [1769581869399] Starting Upmpd Daemon Jan 28 01:31:09 music volumio[6569]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 01:31:09 music volumio[6569]: info: Loading plugin "my_music"... Jan 28 01:31:09 music volumio[6569]: info: Loading plugin "mpd"... Jan 28 01:31:09 music go-librespot[6585]: time="2026-01-28T01:31:09-05:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 01:31:09 music go-librespot[6585]: time="2026-01-28T01:31:09-05:00" level=debug msg="completed keyexchange" Jan 28 01:31:09 music go-librespot[6585]: time="2026-01-28T01:31:09-05:00" level=debug msg="completed challenge" Jan 28 01:31:09 music volumio[6569]: info: Loading plugin "upnp_browser"... Jan 28 01:31:09 music volumio-remote-updater[1248]: [2026-01-28 01:31:09] [connect] Successful connection Jan 28 01:31:09 music sudo[6618]: pam_unix(sudo:session): session closed for user root Jan 28 01:31:09 music go-librespot[6585]: time="2026-01-28T01:31:09-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 28 01:31:10 music go-librespot[6585]: time="2026-01-28T01:31:10-05:00" level=debug msg="connected to ap-gew1.spotify.com:443" Jan 28 01:31:10 music go-librespot[6585]: time="2026-01-28T01:31:10-05:00" level=debug msg="completed keyexchange" Jan 28 01:31:10 music go-librespot[6585]: time="2026-01-28T01:31:10-05:00" level=debug msg="completed challenge" Jan 28 01:31:10 music go-librespot[6585]: time="2026-01-28T01:31:10-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 28 01:31:11 music volumio[6569]: info: Starting UPNP Browser Jan 28 01:31:11 music volumio[6569]: info: Loading plugin "alarm-clock"... Jan 28 01:31:11 music go-librespot[6585]: time="2026-01-28T01:31:11-05:00" level=debug msg="connected to ap-gew4.spotify.com:80" Jan 28 01:31:11 music volumio[6569]: info: Loading plugin "airplay_emulation"... Jan 28 01:31:11 music volumio[6569]: info: Starting Shairport Sync Jan 28 01:31:11 music volumio[6569]: info: Loading plugin "last_100"... Jan 28 01:31:11 music volumio[6569]: info: Loading plugin "webradio"... Jan 28 01:31:11 music go-librespot[6585]: time="2026-01-28T01:31:11-05:00" level=debug msg="completed keyexchange" Jan 28 01:31:11 music go-librespot[6585]: time="2026-01-28T01:31:11-05:00" level=debug msg="completed challenge" Jan 28 01:31:11 music volumio[6569]: info: Loading plugin "i2s_dacs"... Jan 28 01:31:11 music volumio[6569]: info: I2S DAC not set, start Auto-detection Jan 28 01:31:11 music volumio[6569]: info: Loading plugin "volumiodiscovery"... Jan 28 01:31:11 music go-librespot[6585]: time="2026-01-28T01:31:11-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 28 01:31:11 music go-librespot[6585]: time="2026-01-28T01:31:11-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 01:31:11 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 01:31:11 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 01:31:11 music volumio[6569]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 28 01:31:11 music volumio[6569]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 01:31:11 music volumio[6569]: *** WARNING *** For more information see Jan 28 01:31:11 music volumio[6569]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 28 01:31:11 music volumio[6569]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 01:31:11 music volumio[6569]: *** WARNING *** For more information see Jan 28 01:31:11 music node[6569]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 28 01:31:11 music node[6569]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 01:31:11 music node[6569]: *** WARNING *** For more information see Jan 28 01:31:11 music node[6569]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 28 01:31:11 music node[6569]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 01:31:11 music node[6569]: *** WARNING *** For more information see Jan 28 01:31:11 music volumio[6569]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 28 01:31:11 music volumio[6569]: info: Discovery: Started advertising with name: music Jan 28 01:31:11 music volumio[6569]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 01:31:11 music volumio[6569]: info: Loading plugin "spop"... Jan 28 01:31:12 music volumio[6569]: info: Loading plugin "outputs"... Jan 28 01:31:12 music volumio[6569]: info: Loading plugin "albumart"... Jan 28 01:31:12 music volumio[6569]: info: Plugin example_plugin is not enabled Jan 28 01:31:12 music volumio[6569]: info: Loading plugin "inputs"... Jan 28 01:31:12 music volumio[6569]: info: Loading plugin "updater_comm"... Jan 28 01:31:12 music volumio[6569]: info: Plugin mpdemulation is not enabled Jan 28 01:31:12 music volumio[6569]: info: Loading plugin "rest_api"... Jan 28 01:31:13 music volumio[6569]: info: Loading plugin "websocket"... Jan 28 01:31:13 music volumio[6569]: info: Starting Socket.io Server version 1.7.4 Jan 28 01:31:13 music volumio[6569]: info: Loading i18n strings for locale en Jan 28 01:31:13 music volumio[6569]: Updating browse sources language Jan 28 01:31:13 music volumio[6569]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 01:31:13 music volumio[6569]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 01:31:13 music volumio[6569]: info: CoreCommandRouter::initPlayerControls Jan 28 01:31:13 music volumio[6569]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:31:13 music volumio[6569]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:31:13 music volumio[6569]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:31:13 music volumio[6569]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:31:13 music volumio[6569]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:31:13 music volumio[6569]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:31:13 music volumio[6569]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:31:13 music volumio[6569]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:31:13 music volumio[6569]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 01:31:13 music volumio[6569]: Express server listening on port 3000 Jan 28 01:31:13 music volumio[6569]: [Metrics] WebUI: 6s 611.29ms Jan 28 01:31:13 music volumio[6569]: info: CoreStateMachine::resetVolumioState Jan 28 01:31:13 music volumio[6569]: info: CoreStateMachine::getcurrentVolume Jan 28 01:31:13 music volumio[6569]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 01:31:13 music volumio[6569]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 01:31:13 music volumio[6569]: info: Volumio Network Manager: Network status updated: 1 Jan 28 01:31:13 music volumio-remote-updater[1248]: [2026-01-28 01:31:13] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1769581869 101 Jan 28 01:31:13 music volumio[6642]: Forking 3 albumart workers Jan 28 01:31:13 music volumio[6569]: 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 Jan 28 01:31:13 music volumio[6569]: info: VolumeController:: Volume=86 Mute =false Jan 28 01:31:13 music volumio[6569]: info: CoreStateMachine::pushState Jan 28 01:31:13 music volumio[6569]: info: CorePlayQueue::getTrack 0 Jan 28 01:31:13 music volumio[6569]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 01:31:13 music volumio[6569]: info: CoreCommandRouter::volumioPushState Jan 28 01:31:13 music volumio[6569]: info: CoreStateMachine::updateTrackBlock Jan 28 01:31:13 music volumio[6569]: info: CorePlayQueue::getTrackBlock Jan 28 01:31:13 music volumio[6569]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 01:31:13 music volumio[6569]: info: Reloading queue from file Jan 28 01:31:13 music volumio[6569]: info: CoreCommandRouter::volumioGetState Jan 28 01:31:13 music volumio[6569]: info: CorePlayQueue::getTrack 0 Jan 28 01:31:13 music volumio[6569]: info: CoreStateMachine::setRepeat null single undefined Jan 28 01:31:13 music volumio[6569]: info: CoreStateMachine::pushState Jan 28 01:31:13 music volumio[6569]: info: CorePlayQueue::getTrack 0 Jan 28 01:31:13 music volumio[6569]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 01:31:13 music volumio[6569]: info: CoreCommandRouter::volumioPushState Jan 28 01:31:13 music volumio[6569]: info: CoreStateMachine::setRandom null Jan 28 01:31:13 music volumio[6569]: info: CoreStateMachine::pushState Jan 28 01:31:13 music volumio[6569]: info: CorePlayQueue::getTrack 0 Jan 28 01:31:13 music volumio[6569]: info: CoreCommandRouter::volumioPushState Jan 28 01:31:13 music volumio[6569]: info: Setting Device type: Raspberry PI Jan 28 01:31:13 music volumio[6569]: info: Listing playlists Jan 28 01:31:13 music volumio[6569]: info: Listing playlists Jan 28 01:31:13 music volumio[6569]: info: VolumeController:: Volume=86 Mute =false Jan 28 01:31:13 music volumio[6569]: info: CoreStateMachine::pushState Jan 28 01:31:13 music volumio[6569]: info: CorePlayQueue::getTrack 0 Jan 28 01:31:13 music volumio[6569]: info: CoreCommandRouter::volumioPushState Jan 28 01:31:13 music volumio[6569]: info: Completed loading Core Plugins Jan 28 01:31:13 music volumio[6569]: info: Preparing to generate the ALSA configuration file Jan 28 01:31:13 music volumio[6569]: info: Discovery: adding 4a29b7a7-c637-4926-a2bd-fb4e2f55145e Jan 28 01:31:13 music volumio[6569]: info: Discovery: Found device music Jan 28 01:31:13 music volumio[6569]: info: CoreCommandRouter::volumioGetState Jan 28 01:31:13 music volumio[6569]: info: CorePlayQueue::getTrack 0 Jan 28 01:31:13 music volumio[6569]: info: Discovery: this is already registered, 4a29b7a7-c637-4926-a2bd-fb4e2f55145e Jan 28 01:31:13 music volumio[6569]: info: Discovery: Found device music Jan 28 01:31:13 music volumio[6569]: info: CoreCommandRouter::volumioGetState Jan 28 01:31:13 music volumio[6569]: info: CorePlayQueue::getTrack 0 Jan 28 01:31:13 music volumio[6569]: info: Asound.conf file unchanged, so no further update is needed Jan 28 01:31:13 music volumio[6569]: info: Output device has changed, restarting MPD Jan 28 01:31:13 music volumio[6569]: info: Output device has changed, restarting Shairport Sync Jan 28 01:31:13 music volumio[6569]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:31:13 music volumio[6569]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 01:31:13 music sudo[6697]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 28 01:31:13 music sudo[6697]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 01:31:13 music sudo[6697]: pam_unix(sudo:session): session closed for user root Jan 28 01:31:13 music volumio[6569]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 01:31:13 music volumio[6569]: info: ___________ START PLUGINS ___________ Jan 28 01:31:13 music volumio[6569]: info: ControllerMpd::onStart: Initializing MPD Jan 28 01:31:13 music volumio[6569]: info: Creating MPD Configuration file Jan 28 01:31:13 music sudo[6701]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 28 01:31:13 music sudo[6701]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 01:31:13 music volumio[6569]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 01:31:13 music volumio[6569]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 01:31:13 music volumio[6569]: info: [1769581873955] CoreMusicLibrary::Adding element Media Servers Jan 28 01:31:13 music volumio[6569]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 01:31:13 music sudo[6708]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 28 01:31:13 music sudo[6708]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 01:31:13 music volumio[6569]: info: UPNP Browser: Client initialized successfully Jan 28 01:31:13 music systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 28 01:31:14 music sudo[6708]: pam_unix(sudo:session): session closed for user root Jan 28 01:31:14 music sudo[6709]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 28 01:31:14 music sudo[6709]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 01:31:14 music volumio[6569]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:31:14 music volumio[6569]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 01:31:14 music systemd[1]: mpd.service: Deactivated successfully. Jan 28 01:31:14 music systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 28 01:31:14 music systemd[1]: mpd.service: Consumed 4.181s CPU time. Jan 28 01:31:14 music systemd[1]: mpd.socket: Deactivated successfully. Jan 28 01:31:14 music systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 28 01:31:14 music systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 28 01:31:14 music volumio[6569]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 01:31:14 music volumio[6569]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:31:14 music volumio[6569]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 01:31:14 music systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 28 01:31:14 music volumio[6569]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 01:31:14 music volumio[6569]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 01:31:14 music systemd[1]: Starting mpd.service - Music Player Daemon... Jan 28 01:31:14 music volumio[6569]: info: [1769581874169] CoreMusicLibrary::Adding element Last_100 Jan 28 01:31:14 music volumio[6569]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 01:31:14 music volumio[6569]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 01:31:14 music volumio[6569]: info: [1769581874184] CoreMusicLibrary::Adding element Webradio Jan 28 01:31:14 music volumio[6569]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 01:31:14 music volumio[6569]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 01:31:14 music volumio[6569]: info: Initializing BBC Radios Jan 28 01:31:14 music volumio[6569]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 01:31:14 music volumio[6569]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 01:31:14 music volumio[6569]: info: Creating Spotify config file Jan 28 01:31:14 music volumio[6569]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:31:14 music sudo[6721]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 28 01:31:14 music sudo[6721]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 28 01:31:14 music sudo[6721]: pam_unix(sudo:session): session closed for user root Jan 28 01:31:14 music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Jan 28 01:31:14 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 01:31:14 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 01:31:14 music go-librespot[6738]: go-librespot daemon starting... Jan 28 01:31:14 music volumio[6569]: info: Volumio Calling Home Jan 28 01:31:14 music go-librespot[6739]: time="2026-01-28T01:31:14-05:00" level=info msg="running go-librespot 0.6.2" Jan 28 01:31:15 music volumio[6658]: Starting albumart workers Jan 28 01:31:15 music volumio[6659]: Starting albumart workers Jan 28 01:31:15 music go-librespot[6739]: time="2026-01-28T01:31:15-05:00" level=info msg="zeroconf server listening on port 43745" Jan 28 01:31:15 music volumio[6569]: info: MPD Permissions set Jan 28 01:31:15 music volumio[6569]: info: MPD Permissions set Jan 28 01:31:15 music volumio[6569]: info: Spotify config file written Jan 28 01:31:15 music volumio[6569]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Jan 28 01:31:15 music volumio[6569]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:31:15 music volumio[6569]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:31:15 music volumio[6569]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:31:15 music volumio[6569]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:31:15 music volumio[6569]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:31:15 music volumio[6569]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:31:15 music volumio[6569]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:31:15 music volumio[6569]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:31:15 music sudo[6752]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 28 01:31:15 music sudo[6752]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 01:31:15 music volumio[6569]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 01:31:15 music volumio[6569]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:31:15 music volumio[6569]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:31:15 music volumio[6569]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:31:15 music volumio[6569]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:31:15 music volumio[6569]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:31:15 music volumio[6569]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:31:15 music volumio[6569]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:31:15 music volumio[6569]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:31:15 music volumio[6569]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:31:15 music volumio[6657]: Starting albumart workers Jan 28 01:31:15 music volumio[6569]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 01:31:15 music volumio[6569]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:31:15 music systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Jan 28 01:31:15 music systemd[1]: go-librespot-daemon.service: Killing process 6742 (go-librespot) with signal SIGKILL. Jan 28 01:31:15 music systemd[1]: go-librespot-daemon.service: Deactivated successfully. Jan 28 01:31:15 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 01:31:15 music volumio[6569]: info: No need to fix Spotify hosts Jan 28 01:31:15 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 01:31:15 music go-librespot[6764]: go-librespot daemon starting... Jan 28 01:31:15 music sudo[6752]: pam_unix(sudo:session): session closed for user root Jan 28 01:31:15 music go-librespot[6765]: time="2026-01-28T01:31:15-05:00" level=info msg="running go-librespot 0.6.2" Jan 28 01:31:15 music go-librespot[6765]: time="2026-01-28T01:31:15-05:00" level=debug msg="app state loaded" Jan 28 01:31:16 music go-librespot[6765]: time="2026-01-28T01:31:16-05:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 01:31:16 music volumio[6569]: info: Volumio called home Jan 28 01:31:16 music volumio[6569]: info: Starting Shairport Sync Jan 28 01:31:16 music volumio[6569]: info: Starting Shairport Sync Jan 28 01:31:16 music volumio[6569]: info: Starting Shairport Sync Jan 28 01:31:16 music sudo[6777]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 01:31:16 music sudo[6777]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 01:31:16 music volumio[6569]: info: An error occurred while refreshing Spotify Token Error: Bad Request Jan 28 01:31:16 music sudo[6779]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 01:31:16 music sudo[6779]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 01:31:16 music go-librespot[6765]: time="2026-01-28T01:31:16-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 01:31:16 music go-librespot[6765]: time="2026-01-28T01:31:16-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 01:31:16 music go-librespot[6765]: time="2026-01-28T01:31:16-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 01:31:16 music go-librespot[6765]: time="2026-01-28T01:31:16-05:00" level=info msg="zeroconf server listening on port 33115" Jan 28 01:31:16 music sudo[6781]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 01:31:16 music sudo[6781]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 01:31:16 music systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 28 01:31:16 music systemd[1]: shairport-sync.service: Deactivated successfully. Jan 28 01:31:16 music systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 01:31:16 music systemd[1]: shairport-sync.service: Consumed 1.885s CPU time. Jan 28 01:31:16 music systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 01:31:16 music go-librespot[6765]: time="2026-01-28T01:31:16-05:00" level=debug msg="obtained new client token: AACYyUCioxaeviAHiY98u2piHYY058LeGkU/zD79Hq+JkGOyMuD1rZmqzKGQ+HaWLZIowwfPKby+N/jEh29N8VAor3VuVVH0K3AkS5eEhVYUASppM6BZk0ZqWjBLcPiIEigSQZvVyc75qkvh4NVR6MVP0+TDZhn3GDkQnD89TOPvHFujqyhQoFMRZfVm8rKberWiEiJtxmusMnjlGws+rfiuftFZsXV09Htu6pL8Atz+U3rcfL/pUbY=" Jan 28 01:31:16 music sudo[6777]: pam_unix(sudo:session): session closed for user root Jan 28 01:31:16 music sudo[6779]: pam_unix(sudo:session): session closed for user root Jan 28 01:31:16 music systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 28 01:31:16 music systemd[1]: shairport-sync.service: Deactivated successfully. Jan 28 01:31:16 music systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 01:31:16 music systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 01:31:16 music sudo[6781]: pam_unix(sudo:session): session closed for user root Jan 28 01:31:16 music go-librespot[6765]: time="2026-01-28T01:31:16-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Jan 28 01:31:16 music volumio[6569]: info: Shairport-Sync Started Jan 28 01:31:16 music volumio[6569]: Error adding Membership: Error: addMembership EINVAL Jan 28 01:31:16 music volumio[6569]: info: Shairport-Sync Started Jan 28 01:31:16 music volumio[6569]: info: Shairport-Sync Started Jan 28 01:31:16 music volumio[6569]: info: CoreCommandRouter::volumioGetState Jan 28 01:31:16 music volumio[6569]: info: CorePlayQueue::getTrack 0 Jan 28 01:31:17 music go-librespot[6765]: time="2026-01-28T01:31:17-05:00" level=debug msg="completed keyexchange" Jan 28 01:31:17 music go-librespot[6765]: time="2026-01-28T01:31:17-05:00" level=debug msg="completed challenge" Jan 28 01:31:18 music go-librespot[6765]: time="2026-01-28T01:31:18-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 28 01:31:18 music go-librespot[6765]: time="2026-01-28T01:31:18-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Jan 28 01:31:18 music mpd[6737]: 2026-01-28T01:31:18 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 28 01:31:18 music systemd[1]: Started mpd.service - Music Player Daemon. Jan 28 01:31:18 music sudo[6701]: pam_unix(sudo:session): session closed for user root Jan 28 01:31:18 music sudo[6709]: pam_unix(sudo:session): session closed for user root Jan 28 01:31:18 music go-librespot[6765]: time="2026-01-28T01:31:18-05:00" level=debug msg="completed keyexchange" Jan 28 01:31:18 music go-librespot[6765]: time="2026-01-28T01:31:18-05:00" level=debug msg="completed challenge" Jan 28 01:31:18 music volumio[6569]: info: Completed starting Core Plugins Jan 28 01:31:18 music volumio[6569]: info: ------------------------------------------- Jan 28 01:31:18 music volumio[6569]: info: ----- MyVolumio plugins startup ---- Jan 28 01:31:18 music volumio[6569]: info: ------------------------------------------- Jan 28 01:31:18 music volumio[6569]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 28 01:31:18 music go-librespot[6765]: time="2026-01-28T01:31:18-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 28 01:31:18 music volumio[6569]: error: MPD error: The expression evaluated to a falsy value: Jan 28 01:31:18 music volumio[6569]: assert.ok(self.idling) Jan 28 01:31:18 music volumio[6569]: error: The expression evaluated to a falsy value: Jan 28 01:31:18 music volumio[6569]: assert.ok(self.idling) Jan 28 01:31:18 music volumio[6569]: info: MPD running with PID6737 Jan 28 01:31:18 music volumio[6569]: ,establishing connection Jan 28 01:31:18 music volumio[6569]: error: updateQueue error: null Jan 28 01:31:18 music volumio[6569]: error: updateQueue error: null Jan 28 01:31:19 music volumio[6569]: info: go-librespot daemon successfully initialized Jan 28 01:31:19 music go-librespot[6765]: time="2026-01-28T01:31:19-05:00" level=warning msg="failed to connect to AP ap-gue1.spotify.com:80, retrying with a different AP" error="dial tcp 34.158.255.62:80: connect: connection refused" Jan 28 01:31:19 music go-librespot[6765]: time="2026-01-28T01:31:19-05:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 28 01:31:19 music sudo[6840]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 28 01:31:19 music sudo[6840]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 01:31:19 music sudo[6842]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 28 01:31:19 music sudo[6842]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 01:31:19 music sudo[6840]: pam_unix(sudo:session): session closed for user root Jan 28 01:31:19 music sudo[6842]: pam_unix(sudo:session): session closed for user root Jan 28 01:31:19 music go-librespot[6765]: time="2026-01-28T01:31:19-05:00" level=debug msg="completed keyexchange" Jan 28 01:31:19 music go-librespot[6765]: time="2026-01-28T01:31:19-05:00" level=debug msg="completed challenge" Jan 28 01:31:19 music sudo[6844]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 28 01:31:19 music sudo[6844]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 01:31:19 music sudo[6844]: pam_unix(sudo:session): session closed for user root Jan 28 01:31:19 music go-librespot[6765]: time="2026-01-28T01:31:19-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 28 01:31:19 music volumio[6569]: info: Upmpdcli Daemon Started Jan 28 01:31:20 music go-librespot[6765]: time="2026-01-28T01:31:20-05:00" level=debug msg="connected to ap-gew1.spotify.com:443" Jan 28 01:31:20 music go-librespot[6765]: time="2026-01-28T01:31:20-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 28 01:31:20 music volumio[6569]: info: CoreCommandRouter::volumioGetState Jan 28 01:31:20 music volumio[6569]: info: CorePlayQueue::getTrack 0 Jan 28 01:31:20 music go-librespot[6765]: time="2026-01-28T01:31:20-05:00" level=debug msg="connected to ap-gew4.spotify.com:80" Jan 28 01:31:20 music go-librespot[6765]: time="2026-01-28T01:31:20-05:00" level=debug msg="completed keyexchange" Jan 28 01:31:20 music go-librespot[6765]: time="2026-01-28T01:31:20-05:00" level=debug msg="completed challenge" Jan 28 01:31:21 music go-librespot[6765]: time="2026-01-28T01:31:21-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 28 01:31:21 music go-librespot[6765]: time="2026-01-28T01:31:21-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Jan 28 01:31:21 music sudo[6849]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Jan 28 01:31:21 music go-librespot[6765]: time="2026-01-28T01:31:21-05:00" level=debug msg="completed keyexchange" Jan 28 01:31:21 music go-librespot[6765]: time="2026-01-28T01:31:21-05:00" level=debug msg="completed challenge" Jan 28 01:31:21 music sudo[6849]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 01:31:21 music sudo[6851]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Jan 28 01:31:21 music sudo[6851]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 01:31:21 music systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Jan 28 01:31:21 music systemd[1]: mpd_monitor.service: Deactivated successfully. Jan 28 01:31:21 music systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Jan 28 01:31:21 music go-librespot[6765]: time="2026-01-28T01:31:21-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 28 01:31:21 music go-librespot[6765]: time="2026-01-28T01:31:21-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 01:31:21 music systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Jan 28 01:31:21 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 01:31:21 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 01:31:21 music sudo[6851]: pam_unix(sudo:session): session closed for user root Jan 28 01:31:21 music sudo[6849]: pam_unix(sudo:session): session closed for user root Jan 28 01:31:21 music mpd_monitor.sh[6854]: MPD Monitor Service: Starting MPD Monitor Service Jan 28 01:31:21 music volumio[6569]: info: Successfully started MPD Monitor Jan 28 01:31:21 music volumio[6569]: info: Successfully started MPD Monitor Jan 28 01:31:22 music volumio[6569]: info: Initializing connection to go-librespot Websocket Jan 28 01:31:22 music volumio[6569]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 01:31:23 music volumio[6569]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 28 01:31:25 music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Jan 28 01:31:25 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 01:31:25 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 01:31:25 music go-librespot[6858]: go-librespot daemon starting... Jan 28 01:31:25 music go-librespot[6859]: time="2026-01-28T01:31:25-05:00" level=info msg="running go-librespot 0.6.2" Jan 28 01:31:25 music go-librespot[6859]: time="2026-01-28T01:31:25-05:00" level=debug msg="app state loaded" Jan 28 01:31:25 music go-librespot[6859]: time="2026-01-28T01:31:25-05:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 01:31:25 music volumio[6569]: info: Initializing connection to go-librespot Websocket Jan 28 01:31:25 music go-librespot[6859]: time="2026-01-28T01:31:25-05:00" level=debug msg="new websocket client" Jan 28 01:31:25 music volumio[6569]: info: Connection to go-librespot Websocket established Jan 28 01:31:25 music go-librespot[6859]: time="2026-01-28T01:31:25-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-gae2.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 01:31:25 music go-librespot[6859]: time="2026-01-28T01:31:25-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 01:31:25 music go-librespot[6859]: time="2026-01-28T01:31:25-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 01:31:25 music go-librespot[6859]: time="2026-01-28T01:31:25-05:00" level=info msg="zeroconf server listening on port 40747" Jan 28 01:31:25 music go-librespot[6859]: time="2026-01-28T01:31:25-05:00" level=debug msg="obtained new client token: AABtYDEbF9egKpSMlaHc4dFnyDWVimZnifI4282Ko2gsqw/zIlvdE8KtF1PmPEHnEpCrtR0kGCCQ3TPai7V+c1pUNUFBstxeId8IGMrGkmmY9jVJbtCRolopd9kRlwYdROLjezAH14JrbuixcceDPhDi8ugEgzmYBk0HrwmlAgg5iNWR5eOG0vU7Ih4XrpIyExlB+ZP0Ssl6EPKCBQt2JdPOXO6fFrVGh8VGkQ/MGVlmejAejuekY/Y=" Jan 28 01:31:25 music go-librespot[6859]: time="2026-01-28T01:31:25-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Jan 28 01:31:25 music go-librespot[6859]: time="2026-01-28T01:31:25-05:00" level=debug msg="completed keyexchange" Jan 28 01:31:25 music go-librespot[6859]: time="2026-01-28T01:31:25-05:00" level=debug msg="completed challenge" Jan 28 01:31:25 music go-librespot[6859]: time="2026-01-28T01:31:25-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 28 01:31:26 music go-librespot[6859]: time="2026-01-28T01:31:26-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Jan 28 01:31:26 music go-librespot[6859]: time="2026-01-28T01:31:26-05:00" level=debug msg="completed keyexchange" Jan 28 01:31:26 music go-librespot[6859]: time="2026-01-28T01:31:26-05:00" level=debug msg="completed challenge" Jan 28 01:31:26 music go-librespot[6859]: time="2026-01-28T01:31:26-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 28 01:31:27 music volumio[6569]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 28 01:31:27 music volumio[6569]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 28 01:31:27 music volumio[6569]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 28 01:31:27 music volumio[6569]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jan 28 01:31:27 music volumio[6569]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 28 01:31:27 music volumio[6569]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 28 01:31:27 music volumio[6569]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 28 01:31:27 music volumio[6569]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 28 01:31:27 music volumio[6569]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 28 01:31:27 music volumio[6569]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 28 01:31:27 music volumio[6569]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jan 28 01:31:27 music volumio[6569]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 28 01:31:27 music volumio[6569]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 28 01:31:27 music volumio[6569]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 28 01:31:27 music volumio[6569]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jan 28 01:31:27 music volumio[6569]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 28 01:31:27 music volumio[6569]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 28 01:31:27 music volumio[6569]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 28 01:31:27 music volumio[6569]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 28 01:31:27 music volumio[6569]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 28 01:31:27 music volumio[6569]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 28 01:31:27 music volumio[6569]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jan 28 01:31:27 music volumio[6569]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 28 01:31:27 music volumio[6569]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jan 28 01:31:27 music volumio[6569]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 28 01:31:27 music volumio[6569]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 28 01:31:27 music volumio[6569]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 28 01:31:27 music volumio[6569]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 28 01:31:27 music volumio[6569]: info: Adding plugin bluetooth to MyMusic Plugins Jan 28 01:31:27 music volumio[6569]: info: Adding plugin multiroom to MyMusic Plugins Jan 28 01:31:27 music volumio[6569]: info: Adding plugin metavolumio to MyMusic Plugins Jan 28 01:31:27 music volumio[6569]: info: Adding plugin cd_controller to MyMusic Plugins Jan 28 01:31:27 music volumio[6569]: info: Adding plugin qobuzconnect to MyMusic Plugins Jan 28 01:31:27 music volumio[6569]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 28 01:31:27 music volumio[6569]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 28 01:31:27 music volumio[6569]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 28 01:31:27 music go-librespot[6859]: time="2026-01-28T01:31:27-05:00" level=debug msg="connected to ap-gue1.spotify.com:80" Jan 28 01:31:27 music go-librespot[6859]: time="2026-01-28T01:31:27-05:00" level=debug msg="completed keyexchange" Jan 28 01:31:27 music go-librespot[6859]: time="2026-01-28T01:31:27-05:00" level=debug msg="completed challenge" Jan 28 01:31:27 music go-librespot[6859]: time="2026-01-28T01:31:27-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 28 01:31:27 music go-librespot[6859]: time="2026-01-28T01:31:27-05:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 01:31:28 music go-librespot[6859]: time="2026-01-28T01:31:28-05:00" level=debug msg="completed keyexchange" Jan 28 01:31:28 music go-librespot[6859]: time="2026-01-28T01:31:28-05:00" level=debug msg="completed challenge" Jan 28 01:31:28 music volumio[6569]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 28 01:31:28 music volumio[6569]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 28 01:31:28 music volumio[6569]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 01:31:28 music volumio[6569]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 01:31:28 music volumio[6569]: info: Starting MyVolumio Remote Streaming Endpoints Jan 28 01:31:28 music volumio[6569]: info: MyVolumio login type: Token Jan 28 01:31:28 music volumio[6569]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 28 01:31:28 music volumio[6569]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 28 01:31:28 music go-librespot[6859]: time="2026-01-28T01:31:28-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 28 01:31:28 music go-librespot[6859]: time="2026-01-28T01:31:28-05:00" level=debug msg="connected to ap-gew1.spotify.com:443" Jan 28 01:31:29 music go-librespot[6859]: time="2026-01-28T01:31:29-05:00" level=debug msg="completed keyexchange" Jan 28 01:31:29 music go-librespot[6859]: time="2026-01-28T01:31:29-05:00" level=debug msg="completed challenge" Jan 28 01:31:29 music volumio[6569]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 28 01:31:29 music volumio[6569]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 28 01:31:29 music volumio[6569]: info: Streaming services startup Jan 28 01:31:29 music volumio[6569]: info: Starting Streaming Daemon Jan 28 01:31:29 music sudo[6869]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 28 01:31:29 music sudo[6869]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 01:31:29 music volumio[6569]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 28 01:31:29 music sudo[6869]: pam_unix(sudo:session): session closed for user root Jan 28 01:31:29 music go-librespot[6859]: time="2026-01-28T01:31:29-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 28 01:31:29 music volumio[6569]: info: Getting Spotify volume Jan 28 01:31:29 music volumio[6569]: error: Cannot start Volumio Streaming Daemon Jan 28 01:31:29 music volumio[6569]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 28 01:31:29 music volumio[6569]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 28 01:31:29 music volumio[6569]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Jan 28 01:31:29 music volumio[6569]: info: CoreCommandRouter::volumioGetState Jan 28 01:31:29 music volumio[6569]: info: CorePlayQueue::getTrack 0 Jan 28 01:31:29 music volumio[6569]: SPOTIFY: RECEIVED VOLUMIO VOLUME 86 Jan 28 01:31:29 music volumio[6569]: SPOTIFY: SPOTIFY VOLUME undefined Jan 28 01:31:29 music volumio[6569]: SPOTIFY: VOLUMIO VOLUME 86 Jan 28 01:31:29 music volumio[6569]: info: Aligning Spotify Volume to Volumio Volume Jan 28 01:31:29 music volumio[6569]: info: CoreCommandRouter::volumioGetState Jan 28 01:31:29 music volumio[6569]: info: CorePlayQueue::getTrack 0 Jan 28 01:31:29 music volumio[6569]: info: Setting Spotify Volume from Volumio: 86 Jan 28 01:31:29 music volumio[6569]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Jan 28 01:31:29 music go-librespot[6859]: time="2026-01-28T01:31:29-05:00" level=debug msg="connected to ap-gew4.spotify.com:80" Jan 28 01:31:29 music go-librespot[6859]: time="2026-01-28T01:31:29-05:00" level=debug msg="completed keyexchange" Jan 28 01:31:29 music go-librespot[6859]: time="2026-01-28T01:31:29-05:00" level=debug msg="completed challenge" Jan 28 01:31:30 music go-librespot[6859]: time="2026-01-28T01:31:30-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 28 01:31:30 music go-librespot[6859]: time="2026-01-28T01:31:30-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 01:31:30 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 01:31:30 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 01:31:30 music volumio[6569]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 01:31:30 music volumio[6569]: Error: socket hang up Jan 28 01:31:30 music volumio[6569]: at connResetException (node:internal/errors:720:14) Jan 28 01:31:30 music volumio[6569]: at Socket.socketOnEnd (node:_http_client:519:23) Jan 28 01:31:30 music volumio[6569]: at Socket.emit (node:events:526:35) Jan 28 01:31:30 music volumio[6569]: at endReadableNT (node:internal/streams/readable:1376:12) Jan 28 01:31:30 music volumio[6569]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Jan 28 01:31:30 music volumio[6569]: code: 'ECONNRESET', Jan 28 01:31:30 music volumio[6569]: response: undefined Jan 28 01:31:30 music volumio[6569]: } Jan 28 01:31:30 music volumio[6569]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 01:31:30 music sudo[6904]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-28 01:30' Jan 28 01:31:30 music sudo[6904]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 01:31:31 music sudo[6904]: pam_unix(sudo:session): session closed for user root Jan 28 01:31:31 music volumio-remote-updater[1248]: [2026-01-28 01:31:31] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Jan 28 01:31:31 music volumio-remote-updater[1248]: [2026-01-28 01:31:31] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Jan 28 01:31:31 music systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 28 01:31:31 music systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 28 01:31:31 music systemd[1]: volumio.service: Consumed 27.126s CPU time. Jan 28 01:31:32 music systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 28 01:31:32 music systemd[1]: dynamicswap.service: Deactivated successfully. Jan 28 01:31:32 music systemd[1]: volumio.service: Scheduled restart job, restart counter is at 32208. Jan 28 01:31:32 music systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 28 01:31:32 music systemd[1]: Stopped volumio.service - Volumio Backend Module. Jan 28 01:31:32 music systemd[1]: volumio.service: Consumed 27.126s CPU time. Jan 28 01:31:32 music systemd[1]: Started volumio.service - Volumio Backend Module. Jan 28 01:31:32 music systemd[1]: dynamicswap.service: Deactivated successfully. Jan 28 01:31:33 music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Jan 28 01:31:33 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 01:31:33 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 01:31:33 music go-librespot[6934]: go-librespot daemon starting... Jan 28 01:31:33 music go-librespot[6935]: time="2026-01-28T01:31:33-05:00" level=info msg="running go-librespot 0.6.2" Jan 28 01:31:33 music go-librespot[6935]: time="2026-01-28T01:31:33-05:00" level=debug msg="app state loaded" Jan 28 01:31:33 music go-librespot[6935]: time="2026-01-28T01:31:33-05:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 01:31:33 music go-librespot[6935]: time="2026-01-28T01:31:33-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew1.spotify.com:80]" Jan 28 01:31:33 music go-librespot[6935]: time="2026-01-28T01:31:33-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 28 01:31:33 music go-librespot[6935]: time="2026-01-28T01:31:33-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 28 01:31:33 music go-librespot[6935]: time="2026-01-28T01:31:33-05:00" level=info msg="zeroconf server listening on port 37969" Jan 28 01:31:33 music go-librespot[6935]: time="2026-01-28T01:31:33-05:00" level=debug msg="obtained new client token: AABXTi+utE1HmmPWxiZoR2uhqBQiMs0qmvLzhTUm27v2UpjUtO6OpWXnr9lfOnYFvfu3A9eiHg/suqTaMof2kmXlfYL06RUvOB3+nEakZwE3oQ7azYticsyXOMhzN/uKKcvCdQkRBF3dWAsfXzWmRcxIQszIwxd0iuk71wGMcBHAxjMhIj1ixing6YVO4xZNSa3TQD187G3u8/mBjpOK3exmZIrHYBwa7vLl3ZRLbTd2GRng8SPe30Y=" Jan 28 01:31:33 music go-librespot[6935]: time="2026-01-28T01:31:33-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Jan 28 01:31:34 music go-librespot[6935]: time="2026-01-28T01:31:34-05:00" level=debug msg="completed keyexchange" Jan 28 01:31:34 music go-librespot[6935]: time="2026-01-28T01:31:34-05:00" level=debug msg="completed challenge" Jan 28 01:31:34 music go-librespot[6935]: time="2026-01-28T01:31:34-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 28 01:31:34 music volumio[6919]: info: ------------------------------------------- Jan 28 01:31:34 music volumio[6919]: info: ----- Volumio3 ---- Jan 28 01:31:34 music volumio[6919]: info: ------------------------------------------- Jan 28 01:31:34 music volumio[6919]: info: ----- System startup ---- Jan 28 01:31:34 music volumio[6919]: info: ------------------------------------------- Jan 28 01:31:34 music go-librespot[6935]: time="2026-01-28T01:31:34-05:00" level=warning msg="failed to connect to AP ap-gue1.spotify.com:443, retrying with a different AP" error="dial tcp 34.158.255.62:443: connect: connection refused" Jan 28 01:31:34 music go-librespot[6935]: time="2026-01-28T01:31:34-05:00" level=debug msg="connected to ap-gue1.spotify.com:80" Jan 28 01:31:34 music go-librespot[6935]: time="2026-01-28T01:31:34-05:00" level=debug msg="completed keyexchange" Jan 28 01:31:34 music go-librespot[6935]: time="2026-01-28T01:31:34-05:00" level=debug msg="completed challenge" Jan 28 01:31:34 music go-librespot[6935]: time="2026-01-28T01:31:34-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 28 01:31:35 music volumio[6919]: info: MYVOLUMIO Environment detected Jan 28 01:31:35 music volumio[6919]: info: Plugin folders cleanup Jan 28 01:31:35 music volumio[6919]: info: Scanning into folder /volumio/app/plugins/ Jan 28 01:31:35 music volumio[6919]: info: Scanning category audio_interface Jan 28 01:31:35 music volumio[6919]: info: Scanning category miscellanea Jan 28 01:31:35 music volumio[6919]: info: Scanning category music_service Jan 28 01:31:35 music volumio[6919]: info: Scanning category plugins.json Jan 28 01:31:35 music volumio[6919]: info: Scanning category system_controller Jan 28 01:31:35 music volumio[6919]: info: Scanning category user_interface Jan 28 01:31:35 music volumio[6919]: info: Scanning into folder /data/plugins/ Jan 28 01:31:35 music volumio[6919]: info: Scanning category music_service Jan 28 01:31:35 music volumio[6919]: info: Plugin folders cleanup completed Jan 28 01:31:35 music volumio[6919]: info: ------------------------------------------- Jan 28 01:31:35 music volumio[6919]: info: ----- Core plugins startup ---- Jan 28 01:31:35 music volumio[6919]: info: ------------------------------------------- Jan 28 01:31:35 music volumio[6919]: info: Loading plugins from folder /volumio/app/plugins/ Jan 28 01:31:35 music volumio[6919]: info: Adding plugin upnp to MyMusic Plugins Jan 28 01:31:35 music volumio[6919]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 28 01:31:35 music volumio[6919]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 28 01:31:35 music volumio[6919]: info: Loading plugins from folder /data/plugins/ Jan 28 01:31:35 music volumio[6919]: info: Loading plugin "system"... Jan 28 01:31:35 music volumio[6919]: info: Loading plugin "appearance"... Jan 28 01:31:35 music go-librespot[6935]: time="2026-01-28T01:31:35-05:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 28 01:31:35 music go-librespot[6935]: time="2026-01-28T01:31:35-05:00" level=debug msg="completed keyexchange" Jan 28 01:31:35 music go-librespot[6935]: time="2026-01-28T01:31:35-05:00" level=debug msg="completed challenge" Jan 28 01:31:35 music go-librespot[6935]: time="2026-01-28T01:31:35-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 28 01:31:36 music go-librespot[6935]: time="2026-01-28T01:31:36-05:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 28 01:31:36 music volumio[6919]: info: Loading plugin "network"... Jan 28 01:31:36 music volumio[6919]: info: Refreshing Cached IP Addresses Jan 28 01:31:36 music sudo[6957]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 28 01:31:36 music sudo[6957]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 01:31:36 music sudo[6957]: pam_unix(sudo:session): session closed for user root Jan 28 01:31:36 music sudo[6959]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 28 01:31:36 music sudo[6959]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 01:31:36 music go-librespot[6935]: time="2026-01-28T01:31:36-05:00" level=debug msg="completed keyexchange" Jan 28 01:31:36 music go-librespot[6935]: time="2026-01-28T01:31:36-05:00" level=debug msg="completed challenge" Jan 28 01:31:36 music sudo[6959]: pam_unix(sudo:session): session closed for user root Jan 28 01:31:36 music volumio[6919]: info: Loading plugin "services"... Jan 28 01:31:36 music volumio[6919]: info: Loading plugin "alsa_controller"... Jan 28 01:31:36 music sudo[6967]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 28 01:31:36 music sudo[6967]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 01:31:36 music volumio[6919]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 01:31:36 music volumio[6919]: info: Loading plugin "wizard"... Jan 28 01:31:36 music volumio[6919]: info: Loading plugin "networkfs"... Jan 28 01:31:36 music volumio[6919]: info: Starting Udev Watcher for removable devices Jan 28 01:31:36 music volumio[6919]: info: Ignoring mount for partition: boot Jan 28 01:31:36 music volumio[6919]: info: Ignoring mount for partition: volumio Jan 28 01:31:36 music volumio[6919]: info: Ignoring mount for partition: volumio_data Jan 28 01:31:36 music volumio[6919]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 01:31:36 music volumio[6919]: info: Loading plugin "volumio_command_line_client"... Jan 28 01:31:36 music volumio[6919]: info: Loading plugin "upnp"... Jan 28 01:31:36 music volumio[6919]: info: [1769581896639] Starting Upmpd Daemon Jan 28 01:31:36 music volumio[6919]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 01:31:36 music volumio[6919]: info: Loading plugin "my_music"... Jan 28 01:31:36 music volumio[6919]: info: Loading plugin "mpd"... Jan 28 01:31:36 music go-librespot[6935]: time="2026-01-28T01:31:36-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 28 01:31:36 music volumio-remote-updater[1248]: [2026-01-28 01:31:36] [connect] Successful connection Jan 28 01:31:37 music volumio[6919]: info: Loading plugin "upnp_browser"... Jan 28 01:31:37 music sudo[6967]: pam_unix(sudo:session): session closed for user root Jan 28 01:31:37 music go-librespot[6935]: time="2026-01-28T01:31:37-05:00" level=debug msg="connected to ap-gew1.spotify.com:80" Jan 28 01:31:37 music go-librespot[6935]: time="2026-01-28T01:31:37-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.3.63:41326->104.199.65.9:80: read: connection reset by peer" Jan 28 01:31:37 music go-librespot[6935]: time="2026-01-28T01:31:37-05:00" level=warning msg="failed to connect to AP ap-gue1.spotify.com:4070, retrying with a different AP" error="dial tcp: lookup ap-gue1.spotify.com: device or resource busy" Jan 28 01:31:38 music go-librespot[6935]: time="2026-01-28T01:31:38-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Jan 28 01:31:38 music go-librespot[6935]: time="2026-01-28T01:31:38-05:00" level=debug msg="completed keyexchange" Jan 28 01:31:38 music go-librespot[6935]: time="2026-01-28T01:31:38-05:00" level=debug msg="completed challenge" Jan 28 01:31:38 music go-librespot[6935]: time="2026-01-28T01:31:38-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 28 01:31:38 music go-librespot[6935]: time="2026-01-28T01:31:38-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 01:31:38 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 01:31:38 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 01:31:38 music volumio[6919]: info: Starting UPNP Browser Jan 28 01:31:38 music volumio[6919]: info: Loading plugin "alarm-clock"... Jan 28 01:31:38 music volumio[6919]: info: Loading plugin "airplay_emulation"... Jan 28 01:31:38 music volumio[6919]: info: Starting Shairport Sync Jan 28 01:31:38 music volumio[6919]: info: Loading plugin "last_100"... Jan 28 01:31:38 music volumio[6919]: info: Loading plugin "webradio"... Jan 28 01:31:38 music volumio[6919]: info: Loading plugin "i2s_dacs"... Jan 28 01:31:38 music volumio[6919]: info: I2S DAC not set, start Auto-detection Jan 28 01:31:38 music volumio[6919]: info: Loading plugin "volumiodiscovery"... Jan 28 01:31:38 music volumio[6919]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 28 01:31:38 music volumio[6919]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 01:31:38 music volumio[6919]: *** WARNING *** For more information see Jan 28 01:31:38 music volumio[6919]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 28 01:31:38 music volumio[6919]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 01:31:38 music volumio[6919]: *** WARNING *** For more information see Jan 28 01:31:38 music node[6919]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 28 01:31:38 music node[6919]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 01:31:38 music node[6919]: *** WARNING *** For more information see Jan 28 01:31:38 music node[6919]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 28 01:31:38 music node[6919]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 01:31:38 music node[6919]: *** WARNING *** For more information see Jan 28 01:31:38 music volumio[6919]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 28 01:31:38 music volumio[6919]: info: Discovery: Started advertising with name: music Jan 28 01:31:38 music volumio[6919]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 01:31:38 music volumio[6919]: info: Loading plugin "spop"... Jan 28 01:31:40 music volumio[6919]: info: Loading plugin "outputs"... Jan 28 01:31:40 music volumio[6919]: info: Loading plugin "albumart"... Jan 28 01:31:40 music volumio[6919]: info: Plugin example_plugin is not enabled Jan 28 01:31:40 music volumio[6919]: info: Loading plugin "inputs"... Jan 28 01:31:40 music volumio[6919]: info: Loading plugin "updater_comm"... Jan 28 01:31:40 music volumio[6919]: info: Plugin mpdemulation is not enabled Jan 28 01:31:40 music volumio[6919]: info: Loading plugin "rest_api"... Jan 28 01:31:40 music volumio[6919]: info: Loading plugin "websocket"... Jan 28 01:31:40 music volumio[6919]: info: Starting Socket.io Server version 1.7.4 Jan 28 01:31:40 music volumio[6919]: info: Loading i18n strings for locale en Jan 28 01:31:40 music volumio[6919]: Updating browse sources language Jan 28 01:31:40 music volumio[6919]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 01:31:40 music volumio[6919]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 01:31:40 music volumio[6919]: info: CoreCommandRouter::initPlayerControls Jan 28 01:31:40 music volumio[6919]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:31:40 music volumio[6919]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:31:40 music volumio[6919]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:31:40 music volumio[6919]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:31:40 music volumio[6919]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:31:40 music volumio[6919]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:31:40 music volumio[6919]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:31:40 music volumio[6919]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:31:40 music volumio[6919]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 01:31:40 music volumio[6919]: Express server listening on port 3000 Jan 28 01:31:40 music volumio[6919]: [Metrics] WebUI: 6s 650.03ms Jan 28 01:31:40 music volumio[6919]: info: CoreStateMachine::resetVolumioState Jan 28 01:31:40 music volumio[6919]: info: CoreStateMachine::getcurrentVolume Jan 28 01:31:40 music volumio[6919]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 01:31:40 music volumio[6919]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 01:31:40 music volumio[6919]: info: Volumio Network Manager: Network status updated: 1 Jan 28 01:31:40 music volumio-remote-updater[1248]: [2026-01-28 01:31:40] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1769581896 101 Jan 28 01:31:40 music volumio[6992]: Forking 3 albumart workers Jan 28 01:31:40 music volumio[6919]: 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 Jan 28 01:31:40 music volumio[6919]: info: VolumeController:: Volume=86 Mute =false Jan 28 01:31:40 music volumio[6919]: info: CoreStateMachine::pushState Jan 28 01:31:40 music volumio[6919]: info: CorePlayQueue::getTrack 0 Jan 28 01:31:40 music volumio[6919]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 01:31:40 music volumio[6919]: info: CoreCommandRouter::volumioPushState Jan 28 01:31:40 music volumio[6919]: info: CoreStateMachine::updateTrackBlock Jan 28 01:31:40 music volumio[6919]: info: CorePlayQueue::getTrackBlock Jan 28 01:31:40 music volumio[6919]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 01:31:40 music volumio[6919]: info: Reloading queue from file Jan 28 01:31:40 music volumio[6919]: info: CoreStateMachine::setRepeat null single undefined Jan 28 01:31:40 music volumio[6919]: info: CoreStateMachine::pushState Jan 28 01:31:40 music volumio[6919]: info: CorePlayQueue::getTrack 0 Jan 28 01:31:40 music volumio[6919]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 01:31:40 music volumio[6919]: info: CoreCommandRouter::volumioPushState Jan 28 01:31:40 music volumio[6919]: info: CoreStateMachine::setRandom null Jan 28 01:31:40 music volumio[6919]: info: CoreStateMachine::pushState Jan 28 01:31:40 music volumio[6919]: info: CorePlayQueue::getTrack 0 Jan 28 01:31:40 music volumio[6919]: info: CoreCommandRouter::volumioPushState Jan 28 01:31:40 music volumio[6919]: info: Setting Device type: Raspberry PI Jan 28 01:31:40 music volumio[6919]: info: CoreCommandRouter::volumioGetState Jan 28 01:31:40 music volumio[6919]: info: CorePlayQueue::getTrack 0 Jan 28 01:31:41 music volumio[6919]: info: VolumeController:: Volume=86 Mute =false Jan 28 01:31:41 music volumio[6919]: info: CoreStateMachine::pushState Jan 28 01:31:41 music volumio[6919]: info: CorePlayQueue::getTrack 0 Jan 28 01:31:41 music volumio[6919]: info: CoreCommandRouter::volumioPushState Jan 28 01:31:41 music volumio[6919]: info: Listing playlists Jan 28 01:31:41 music volumio[6919]: info: Listing playlists Jan 28 01:31:41 music volumio[6919]: info: Discovery: adding 4a29b7a7-c637-4926-a2bd-fb4e2f55145e Jan 28 01:31:41 music volumio[6919]: info: Discovery: Found device music Jan 28 01:31:41 music volumio[6919]: info: CoreCommandRouter::volumioGetState Jan 28 01:31:41 music volumio[6919]: info: CorePlayQueue::getTrack 0 Jan 28 01:31:41 music volumio[6919]: info: Discovery: this is already registered, 4a29b7a7-c637-4926-a2bd-fb4e2f55145e Jan 28 01:31:41 music volumio[6919]: info: Discovery: Found device music Jan 28 01:31:41 music volumio[6919]: info: CoreCommandRouter::volumioGetState Jan 28 01:31:41 music volumio[6919]: info: CorePlayQueue::getTrack 0 Jan 28 01:31:41 music volumio[6919]: info: Completed loading Core Plugins Jan 28 01:31:41 music volumio[6919]: info: Preparing to generate the ALSA configuration file Jan 28 01:31:41 music volumio[6919]: info: Asound.conf file unchanged, so no further update is needed Jan 28 01:31:41 music volumio[6919]: info: Output device has changed, restarting MPD Jan 28 01:31:41 music volumio[6919]: info: Output device has changed, restarting Shairport Sync Jan 28 01:31:41 music volumio[6919]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:31:41 music volumio[6919]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 01:31:41 music sudo[7047]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 28 01:31:41 music sudo[7047]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 01:31:41 music sudo[7047]: pam_unix(sudo:session): session closed for user root Jan 28 01:31:41 music sudo[7049]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 28 01:31:41 music volumio[6919]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 01:31:41 music sudo[7049]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 01:31:41 music volumio[6919]: info: ___________ START PLUGINS ___________ Jan 28 01:31:41 music volumio[6919]: info: ControllerMpd::onStart: Initializing MPD Jan 28 01:31:41 music volumio[6919]: info: Creating MPD Configuration file Jan 28 01:31:41 music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Jan 28 01:31:41 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 01:31:41 music sudo[7057]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 28 01:31:41 music sudo[7057]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 01:31:41 music volumio[6919]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 01:31:41 music volumio[6919]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 01:31:41 music volumio[6919]: info: [1769581901273] CoreMusicLibrary::Adding element Media Servers Jan 28 01:31:41 music volumio[6919]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 01:31:41 music sudo[7057]: pam_unix(sudo:session): session closed for user root Jan 28 01:31:41 music sudo[7059]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 28 01:31:41 music sudo[7059]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 01:31:41 music volumio[6919]: info: UPNP Browser: Client initialized successfully Jan 28 01:31:41 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 01:31:41 music go-librespot[7060]: go-librespot daemon starting... Jan 28 01:31:41 music systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 28 01:31:41 music volumio[6919]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:31:41 music volumio[6919]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 01:31:41 music go-librespot[7063]: time="2026-01-28T01:31:41-05:00" level=info msg="running go-librespot 0.6.2" Jan 28 01:31:41 music go-librespot[7063]: time="2026-01-28T01:31:41-05:00" level=debug msg="app state loaded" Jan 28 01:31:41 music systemd[1]: mpd.service: Deactivated successfully. Jan 28 01:31:41 music systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 28 01:31:41 music systemd[1]: mpd.service: Consumed 4.210s CPU time. Jan 28 01:31:41 music go-librespot[7063]: time="2026-01-28T01:31:41-05:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 01:31:41 music systemd[1]: mpd.socket: Deactivated successfully. Jan 28 01:31:41 music systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 28 01:31:41 music volumio[6919]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 01:31:41 music volumio[6919]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:31:41 music systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 28 01:31:41 music volumio[6919]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 01:31:41 music volumio[6919]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 01:31:41 music volumio[6919]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 01:31:41 music volumio[6919]: info: [1769581901487] CoreMusicLibrary::Adding element Last_100 Jan 28 01:31:41 music volumio[6919]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 01:31:41 music volumio[6919]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 01:31:41 music volumio[6919]: info: [1769581901499] CoreMusicLibrary::Adding element Webradio Jan 28 01:31:41 music volumio[6919]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 01:31:41 music systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 28 01:31:41 music volumio[6919]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 01:31:41 music systemd[1]: Starting mpd.service - Music Player Daemon... Jan 28 01:31:41 music volumio[6919]: info: Initializing BBC Radios Jan 28 01:31:41 music volumio[6919]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 01:31:41 music volumio[6919]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 01:31:41 music volumio[6919]: info: Creating Spotify config file Jan 28 01:31:41 music volumio[6919]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:31:41 music sudo[7081]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 28 01:31:41 music sudo[7081]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 28 01:31:41 music sudo[7081]: pam_unix(sudo:session): session closed for user root Jan 28 01:31:41 music go-librespot[7063]: time="2026-01-28T01:31:41-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew1.spotify.com:80]" Jan 28 01:31:41 music go-librespot[7063]: time="2026-01-28T01:31:41-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 28 01:31:41 music go-librespot[7063]: time="2026-01-28T01:31:41-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 28 01:31:41 music go-librespot[7063]: time="2026-01-28T01:31:41-05:00" level=info msg="zeroconf server listening on port 43115" Jan 28 01:31:42 music go-librespot[7063]: time="2026-01-28T01:31:42-05:00" level=debug msg="obtained new client token: AACb8sPKh+dRaMwG30JZWJrnRwwNTyqYpTwRbiFHHarSAmGf5W+adULPLwsbB2SCzGK+/bJzJUB+olN/o149g3YITKE9jaEfzW8GdoDPbKQGOaslEtW1VZbXY64UWqHGXUSdQi9jlwlDtuyZuWAhkAFdRRz2foDgKaznCaJx4Gu3Yg3OduUqC9kbzs2tjEKF9XVGKPZEOlTz7SbozAkUI5S01mhFwQEJcBDgd2dTp4HTiBoiFy34" Jan 28 01:31:42 music go-librespot[7063]: time="2026-01-28T01:31:42-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Jan 28 01:31:42 music go-librespot[7063]: time="2026-01-28T01:31:42-05:00" level=debug msg="completed keyexchange" Jan 28 01:31:42 music go-librespot[7063]: time="2026-01-28T01:31:42-05:00" level=debug msg="completed challenge" Jan 28 01:31:42 music go-librespot[7063]: time="2026-01-28T01:31:42-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 28 01:31:42 music volumio[6919]: info: Volumio Calling Home Jan 28 01:31:42 music volumio[7008]: Starting albumart workers Jan 28 01:31:42 music volumio[7009]: Starting albumart workers Jan 28 01:31:42 music go-librespot[7063]: time="2026-01-28T01:31:42-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Jan 28 01:31:42 music volumio[6919]: info: MPD Permissions set Jan 28 01:31:42 music volumio[6919]: info: MPD Permissions set Jan 28 01:31:42 music go-librespot[7063]: time="2026-01-28T01:31:42-05:00" level=debug msg="completed keyexchange" Jan 28 01:31:42 music go-librespot[7063]: time="2026-01-28T01:31:42-05:00" level=debug msg="completed challenge" Jan 28 01:31:42 music volumio[6919]: info: Volumio called home Jan 28 01:31:42 music volumio[6919]: info: Spotify config file written Jan 28 01:31:43 music go-librespot[7063]: time="2026-01-28T01:31:43-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 28 01:31:43 music sudo[7103]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 28 01:31:43 music sudo[7103]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 01:31:43 music volumio[6919]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Jan 28 01:31:43 music volumio[6919]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:31:43 music volumio[6919]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:31:43 music volumio[6919]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:31:43 music volumio[6919]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:31:43 music volumio[6919]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:31:43 music volumio[6919]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:31:43 music volumio[6919]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:31:43 music volumio[6919]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:31:43 music systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Jan 28 01:31:43 music systemd[1]: go-librespot-daemon.service: Deactivated successfully. Jan 28 01:31:43 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 01:31:43 music volumio[6919]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 01:31:43 music volumio[6919]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:31:43 music volumio[6919]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:31:43 music volumio[6919]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:31:43 music volumio[6919]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:31:43 music volumio[6919]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:31:43 music volumio[6919]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:31:43 music volumio[6919]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:31:43 music volumio[6919]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:31:43 music volumio[6919]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:31:43 music go-librespot[7110]: go-librespot daemon starting... Jan 28 01:31:43 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 01:31:43 music sudo[7103]: pam_unix(sudo:session): session closed for user root Jan 28 01:31:43 music volumio[6919]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 01:31:43 music volumio[6919]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 01:31:43 music volumio[6919]: info: No need to fix Spotify hosts Jan 28 01:31:43 music volumio[7010]: Starting albumart workers Jan 28 01:31:43 music go-librespot[7117]: time="2026-01-28T01:31:43-05:00" level=info msg="running go-librespot 0.6.2" Jan 28 01:31:43 music go-librespot[7117]: time="2026-01-28T01:31:43-05:00" level=debug msg="app state loaded" Jan 28 01:31:43 music go-librespot[7117]: time="2026-01-28T01:31:43-05:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 01:31:43 music volumio[6919]: info: An error occurred while refreshing Spotify Token Error: Bad Request Jan 28 01:31:43 music volumio[6919]: info: Starting Shairport Sync Jan 28 01:31:43 music volumio[6919]: info: Starting Shairport Sync Jan 28 01:31:43 music go-librespot[7117]: time="2026-01-28T01:31:43-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gae2.spotify.com:443 ap-gew1.spotify.com:80]" Jan 28 01:31:43 music go-librespot[7117]: time="2026-01-28T01:31:43-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gae2-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 28 01:31:43 music go-librespot[7117]: time="2026-01-28T01:31:43-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gae2-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 28 01:31:43 music go-librespot[7117]: time="2026-01-28T01:31:43-05:00" level=info msg="zeroconf server listening on port 36001" Jan 28 01:31:43 music volumio[6919]: info: Starting Shairport Sync Jan 28 01:31:43 music sudo[7128]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 01:31:43 music sudo[7128]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 01:31:43 music sudo[7130]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 01:31:43 music sudo[7130]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 01:31:44 music systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 28 01:31:44 music systemd[1]: shairport-sync.service: Deactivated successfully. Jan 28 01:31:44 music systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 01:31:44 music systemd[1]: shairport-sync.service: Consumed 1.846s CPU time. Jan 28 01:31:44 music sudo[7133]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 01:31:44 music sudo[7133]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 01:31:44 music go-librespot[7117]: time="2026-01-28T01:31:44-05:00" level=debug msg="obtained new client token: AAAJ+E8iItUPUI8zEKoCrUDPdZAP/3BlXXyIt+7pBUvI7rywNosWlUuH4QFR2+Y9xiNKWBShDlRnF18CktlX0ldp4IbK+Gq1AC7yf1BeUm9zBqSfZ1BEg872I332ozfn8ioSf6U692m8Qu8Coo5lYGre+1ODqgA6JRBGziwQ4nN5lkOPFWfy1ELmayVq8vs5dpTmjDhWKb297iYrcNTcQ+/WlxpPFUFPKU5DrqA3Q4EfQSzW+uwm" Jan 28 01:31:44 music systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 01:31:44 music go-librespot[7117]: time="2026-01-28T01:31:44-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Jan 28 01:31:44 music systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 28 01:31:44 music sudo[7130]: pam_unix(sudo:session): session closed for user root Jan 28 01:31:44 music systemd[1]: shairport-sync.service: Deactivated successfully. Jan 28 01:31:44 music systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 01:31:44 music go-librespot[7117]: time="2026-01-28T01:31:44-05:00" level=debug msg="completed keyexchange" Jan 28 01:31:44 music go-librespot[7117]: time="2026-01-28T01:31:44-05:00" level=debug msg="completed challenge" Jan 28 01:31:44 music systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 01:31:44 music volumio[6919]: info: Shairport-Sync Started Jan 28 01:31:44 music go-librespot[7117]: time="2026-01-28T01:31:44-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 28 01:31:44 music volumio[6919]: Error adding Membership: Error: addMembership EINVAL Jan 28 01:31:44 music sudo[7128]: pam_unix(sudo:session): session closed for user root Jan 28 01:31:44 music sudo[7133]: pam_unix(sudo:session): session closed for user root Jan 28 01:31:44 music volumio[6919]: info: CoreCommandRouter::volumioGetState Jan 28 01:31:44 music volumio[6919]: info: CorePlayQueue::getTrack 0 Jan 28 01:31:44 music volumio[6919]: info: Shairport-Sync Started Jan 28 01:31:44 music volumio[6919]: info: Shairport-Sync Started Jan 28 01:31:44 music go-librespot[7117]: time="2026-01-28T01:31:44-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Jan 28 01:31:44 music go-librespot[7117]: time="2026-01-28T01:31:44-05:00" level=debug msg="completed keyexchange" Jan 28 01:31:44 music go-librespot[7117]: time="2026-01-28T01:31:44-05:00" level=debug msg="completed challenge" Jan 28 01:31:44 music go-librespot[7117]: time="2026-01-28T01:31:44-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 28 01:31:45 music go-librespot[7117]: time="2026-01-28T01:31:45-05:00" level=warning msg="failed to connect to AP ap-gue1.spotify.com:80, retrying with a different AP" error="dial tcp 34.158.255.62:80: connect: connection refused" Jan 28 01:31:45 music go-librespot[7117]: time="2026-01-28T01:31:45-05:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 28 01:31:45 music go-librespot[7117]: time="2026-01-28T01:31:45-05:00" level=debug msg="completed keyexchange" Jan 28 01:31:45 music go-librespot[7117]: time="2026-01-28T01:31:45-05:00" level=debug msg="completed challenge" Jan 28 01:31:45 music go-librespot[7117]: time="2026-01-28T01:31:45-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 28 01:31:45 music mpd[7096]: 2026-01-28T01:31:45 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 28 01:31:45 music systemd[1]: Started mpd.service - Music Player Daemon. Jan 28 01:31:45 music sudo[7059]: pam_unix(sudo:session): session closed for user root Jan 28 01:31:45 music sudo[7049]: pam_unix(sudo:session): session closed for user root Jan 28 01:31:46 music volumio[6919]: info: Completed starting Core Plugins Jan 28 01:31:46 music volumio[6919]: info: ------------------------------------------- Jan 28 01:31:46 music volumio[6919]: info: ----- MyVolumio plugins startup ---- Jan 28 01:31:46 music volumio[6919]: info: ------------------------------------------- Jan 28 01:31:46 music volumio[6919]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 28 01:31:46 music volumio[6919]: error: MPD error: The expression evaluated to a falsy value: Jan 28 01:31:46 music volumio[6919]: assert.ok(self.idling) Jan 28 01:31:46 music volumio[6919]: error: The expression evaluated to a falsy value: Jan 28 01:31:46 music volumio[6919]: assert.ok(self.idling) Jan 28 01:31:46 music volumio[6919]: info: MPD running with PID7096 Jan 28 01:31:46 music volumio[6919]: ,establishing connection Jan 28 01:31:46 music volumio[6919]: error: updateQueue error: null Jan 28 01:31:46 music volumio[6919]: error: updateQueue error: null Jan 28 01:31:46 music go-librespot[7117]: time="2026-01-28T01:31:46-05:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 28 01:31:46 music go-librespot[7117]: time="2026-01-28T01:31:46-05:00" level=debug msg="completed keyexchange" Jan 28 01:31:46 music go-librespot[7117]: time="2026-01-28T01:31:46-05:00" level=debug msg="completed challenge" Jan 28 01:31:46 music sudo[7191]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 28 01:31:46 music sudo[7191]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 01:31:46 music sudo[7191]: pam_unix(sudo:session): session closed for user root Jan 28 01:31:46 music sudo[7193]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 28 01:31:46 music sudo[7193]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 01:31:46 music sudo[7193]: pam_unix(sudo:session): session closed for user root Jan 28 01:31:46 music sudo[7195]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 28 01:31:46 music sudo[7195]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 01:31:46 music volumio[6919]: info: go-librespot daemon successfully initialized Jan 28 01:31:46 music sudo[7195]: pam_unix(sudo:session): session closed for user root Jan 28 01:31:46 music volumio[6919]: info: Upmpdcli Daemon Started Jan 28 01:31:46 music go-librespot[7117]: time="2026-01-28T01:31:46-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 28 01:31:47 music go-librespot[7117]: time="2026-01-28T01:31:47-05:00" level=debug msg="connected to ap-gew1.spotify.com:80" Jan 28 01:31:47 music go-librespot[7117]: time="2026-01-28T01:31:47-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: read tcp 192.168.3.63:60898->104.199.65.9:80: read: connection reset by peer" Jan 28 01:31:48 music go-librespot[7117]: time="2026-01-28T01:31:48-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Jan 28 01:31:48 music go-librespot[7117]: time="2026-01-28T01:31:48-05:00" level=debug msg="completed keyexchange" Jan 28 01:31:48 music go-librespot[7117]: time="2026-01-28T01:31:48-05:00" level=debug msg="completed challenge" Jan 28 01:31:48 music go-librespot[7117]: time="2026-01-28T01:31:48-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 28 01:31:48 music go-librespot[7117]: time="2026-01-28T01:31:48-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 01:31:48 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 01:31:48 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 01:31:49 music sudo[7200]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Jan 28 01:31:49 music sudo[7200]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 01:31:49 music sudo[7202]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Jan 28 01:31:49 music sudo[7202]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 01:31:49 music systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Jan 28 01:31:49 music systemd[1]: mpd_monitor.service: Deactivated successfully. Jan 28 01:31:49 music systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Jan 28 01:31:49 music systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Jan 28 01:31:49 music sudo[7200]: pam_unix(sudo:session): session closed for user root Jan 28 01:31:49 music volumio[6919]: info: Successfully started MPD Monitor Jan 28 01:31:49 music mpd_monitor.sh[7205]: MPD Monitor Service: Starting MPD Monitor Service Jan 28 01:31:49 music sudo[7202]: pam_unix(sudo:session): session closed for user root Jan 28 01:31:49 music volumio[6919]: info: Successfully started MPD Monitor Jan 28 01:31:49 music volumio[6919]: info: Initializing connection to go-librespot Websocket Jan 28 01:31:49 music volumio[6919]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 01:31:50 music volumio[6919]: info: CoreCommandRouter::volumioGetState Jan 28 01:31:50 music volumio[6919]: info: CorePlayQueue::getTrack 0 Jan 28 01:31:51 music volumio[6919]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 28 01:31:51 music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Jan 28 01:31:51 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 01:31:51 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 01:31:51 music go-librespot[7209]: go-librespot daemon starting... Jan 28 01:31:51 music go-librespot[7210]: time="2026-01-28T01:31:51-05:00" level=info msg="running go-librespot 0.6.2" Jan 28 01:31:51 music go-librespot[7210]: time="2026-01-28T01:31:51-05:00" level=debug msg="app state loaded" Jan 28 01:31:51 music go-librespot[7210]: time="2026-01-28T01:31:51-05:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 01:31:51 music go-librespot[7210]: time="2026-01-28T01:31:51-05:00" level=debug msg="fetched new accesspoints: [ap-gue1.spotify.com:4070 ap-gue1.spotify.com:443 ap-gue1.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 01:31:51 music go-librespot[7210]: time="2026-01-28T01:31:51-05:00" level=debug msg="fetched new dealers: [gue1-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 01:31:51 music go-librespot[7210]: time="2026-01-28T01:31:51-05:00" level=debug msg="fetched new spclients: [gue1-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 01:31:51 music go-librespot[7210]: time="2026-01-28T01:31:51-05:00" level=info msg="zeroconf server listening on port 46369" Jan 28 01:31:51 music go-librespot[7210]: time="2026-01-28T01:31:51-05:00" level=debug msg="obtained new client token: AADHlgBWgY18osyt0KvkBB3XlTx2shYjo+H44D/bQNyITW6LoYCvVt1aevBIg1pgHuvFsJcEg0VA+lMYnxP8lkKatJnlz37rH2CDE6+91SJyG85vmYN9QRWrIxM8ldq5sJFzMjKqjbqusuNi3KFKomMaz26gyh53WaSi3gvxHikRCElSHcMww49OZJq6JgPEubezfYMaFKh660PHcDiKl/wGP8UKTGXC/Tn38E6VCC8Imk8twtkF2PI=" Jan 28 01:31:51 music go-librespot[7210]: time="2026-01-28T01:31:51-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Jan 28 01:31:51 music go-librespot[7210]: time="2026-01-28T01:31:51-05:00" level=debug msg="completed keyexchange" Jan 28 01:31:51 music go-librespot[7210]: time="2026-01-28T01:31:51-05:00" level=debug msg="completed challenge" Jan 28 01:31:52 music go-librespot[7210]: time="2026-01-28T01:31:52-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 28 01:31:52 music go-librespot[7210]: time="2026-01-28T01:31:52-05:00" level=warning msg="failed to connect to AP ap-gue1.spotify.com:443, retrying with a different AP" error="dial tcp 34.158.255.62:443: connect: connection refused" Jan 28 01:31:52 music go-librespot[7210]: time="2026-01-28T01:31:52-05:00" level=debug msg="connected to ap-gue1.spotify.com:80" Jan 28 01:31:52 music go-librespot[7210]: time="2026-01-28T01:31:52-05:00" level=debug msg="completed keyexchange" Jan 28 01:31:52 music go-librespot[7210]: time="2026-01-28T01:31:52-05:00" level=debug msg="completed challenge" Jan 28 01:31:52 music volumio[6919]: info: Initializing connection to go-librespot Websocket Jan 28 01:31:52 music go-librespot[7210]: time="2026-01-28T01:31:52-05:00" level=debug msg="new websocket client" Jan 28 01:31:52 music volumio[6919]: info: Connection to go-librespot Websocket established Jan 28 01:31:52 music go-librespot[7210]: time="2026-01-28T01:31:52-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 28 01:31:53 music go-librespot[7210]: time="2026-01-28T01:31:53-05:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 28 01:31:53 music go-librespot[7210]: time="2026-01-28T01:31:53-05:00" level=debug msg="completed keyexchange" Jan 28 01:31:53 music go-librespot[7210]: time="2026-01-28T01:31:53-05:00" level=debug msg="completed challenge" Jan 28 01:31:53 music go-librespot[7210]: time="2026-01-28T01:31:53-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 28 01:31:54 music go-librespot[7210]: time="2026-01-28T01:31:54-05:00" level=warning msg="failed to connect to AP ap-gew1.spotify.com:443, retrying with a different AP" error="dial tcp 104.199.65.9:443: connect: connection refused" Jan 28 01:31:54 music go-librespot[7210]: time="2026-01-28T01:31:54-05:00" level=debug msg="connected to ap-gew4.spotify.com:80" Jan 28 01:31:54 music go-librespot[7210]: time="2026-01-28T01:31:54-05:00" level=debug msg="completed keyexchange" Jan 28 01:31:54 music go-librespot[7210]: time="2026-01-28T01:31:54-05:00" level=debug msg="completed challenge" Jan 28 01:31:54 music volumio[6919]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 28 01:31:54 music volumio[6919]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 28 01:31:54 music volumio[6919]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 28 01:31:54 music volumio[6919]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jan 28 01:31:54 music volumio[6919]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 28 01:31:54 music volumio[6919]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 28 01:31:54 music volumio[6919]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 28 01:31:54 music volumio[6919]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 28 01:31:54 music volumio[6919]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 28 01:31:54 music volumio[6919]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 28 01:31:54 music volumio[6919]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jan 28 01:31:54 music volumio[6919]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 28 01:31:54 music volumio[6919]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 28 01:31:54 music volumio[6919]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 28 01:31:54 music volumio[6919]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jan 28 01:31:54 music volumio[6919]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 28 01:31:54 music volumio[6919]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 28 01:31:54 music volumio[6919]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 28 01:31:54 music volumio[6919]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 28 01:31:54 music volumio[6919]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 28 01:31:54 music volumio[6919]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 28 01:31:54 music volumio[6919]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jan 28 01:31:54 music volumio[6919]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 28 01:31:54 music volumio[6919]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jan 28 01:31:54 music volumio[6919]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 28 01:31:54 music volumio[6919]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 28 01:31:54 music volumio[6919]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 28 01:31:54 music volumio[6919]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 28 01:31:54 music volumio[6919]: info: Adding plugin bluetooth to MyMusic Plugins Jan 28 01:31:54 music volumio[6919]: info: Adding plugin multiroom to MyMusic Plugins Jan 28 01:31:54 music volumio[6919]: info: Adding plugin metavolumio to MyMusic Plugins Jan 28 01:31:54 music volumio[6919]: info: Adding plugin cd_controller to MyMusic Plugins Jan 28 01:31:54 music volumio[6919]: info: Adding plugin qobuzconnect to MyMusic Plugins Jan 28 01:31:54 music volumio[6919]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 28 01:31:54 music volumio[6919]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 28 01:31:54 music volumio[6919]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 28 01:31:54 music go-librespot[7210]: time="2026-01-28T01:31:54-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 28 01:31:55 music go-librespot[7210]: time="2026-01-28T01:31:55-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Jan 28 01:31:55 music go-librespot[7210]: time="2026-01-28T01:31:55-05:00" level=debug msg="completed keyexchange" Jan 28 01:31:55 music go-librespot[7210]: time="2026-01-28T01:31:55-05:00" level=debug msg="completed challenge" Jan 28 01:31:55 music go-librespot[7210]: time="2026-01-28T01:31:55-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 28 01:31:55 music volumio[6919]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 28 01:31:55 music volumio[6919]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 28 01:31:55 music volumio[6919]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 01:31:55 music volumio[6919]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 01:31:55 music volumio[6919]: info: Starting MyVolumio Remote Streaming Endpoints Jan 28 01:31:55 music volumio[6919]: info: MyVolumio login type: Token Jan 28 01:31:55 music volumio[6919]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 28 01:31:55 music volumio[6919]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 28 01:31:55 music go-librespot[7210]: time="2026-01-28T01:31:55-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Jan 28 01:31:55 music go-librespot[7210]: time="2026-01-28T01:31:55-05:00" level=debug msg="completed keyexchange" Jan 28 01:31:55 music go-librespot[7210]: time="2026-01-28T01:31:55-05:00" level=debug msg="completed challenge" Jan 28 01:31:55 music go-librespot[7210]: time="2026-01-28T01:31:55-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 28 01:31:55 music go-librespot[7210]: time="2026-01-28T01:31:55-05:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 01:31:55 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 01:31:55 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 01:31:56 music volumio[6919]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 28 01:31:56 music volumio[6919]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 28 01:31:56 music volumio[6919]: info: Streaming services startup Jan 28 01:31:56 music volumio[6919]: info: Starting Streaming Daemon Jan 28 01:31:56 music sudo[7220]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 28 01:31:56 music sudo[7220]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 01:31:56 music volumio[6919]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 28 01:31:56 music sudo[7220]: pam_unix(sudo:session): session closed for user root Jan 28 01:31:56 music volumio[6919]: info: Getting Spotify volume Jan 28 01:31:56 music volumio[6919]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 01:31:56 music volumio[6919]: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 01:31:56 music volumio[6919]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Jan 28 01:31:56 music volumio[6919]: errno: -111, Jan 28 01:31:56 music volumio[6919]: code: 'ECONNREFUSED', Jan 28 01:31:56 music volumio[6919]: syscall: 'connect', Jan 28 01:31:56 music volumio[6919]: address: '127.0.0.1', Jan 28 01:31:56 music volumio[6919]: port: 9879, Jan 28 01:31:56 music volumio[6919]: response: undefined Jan 28 01:31:56 music volumio[6919]: } Jan 28 01:31:56 music volumio[6919]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 01:31:57 music sudo[7255]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-28 01:30' Jan 28 01:31:57 music sudo[7255]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="cfdc872d40b979cca36352a7333c940c38dc64b5" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="6cbc2303e10f00c3a01cb7f02c6d12448bd32c62" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri Dec 5 20:42:14 UTC 2025" VOLUMIO_VERSION="4.073" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="67fdc5f60f00b7a328ccd8c4ad441086"