Jan 25 12:33:00 music volumio[19706]: info: Starting UPNP Browser Jan 25 12:33:00 music volumio[19706]: info: Loading plugin "alarm-clock"... Jan 25 12:33:01 music volumio[19706]: info: Loading plugin "airplay_emulation"... Jan 25 12:33:01 music volumio[19706]: info: Starting Shairport Sync Jan 25 12:33:01 music volumio[19706]: info: Loading plugin "last_100"... Jan 25 12:33:01 music volumio[19706]: info: Loading plugin "webradio"... Jan 25 12:33:01 music volumio[19706]: info: Loading plugin "i2s_dacs"... Jan 25 12:33:01 music volumio[19706]: info: I2S DAC not set, start Auto-detection Jan 25 12:33:01 music volumio[19706]: info: Loading plugin "volumiodiscovery"... Jan 25 12:33:01 music volumio[19706]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 25 12:33:01 music volumio[19706]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 25 12:33:01 music volumio[19706]: *** WARNING *** For more information see Jan 25 12:33:01 music volumio[19706]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 25 12:33:01 music volumio[19706]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 25 12:33:01 music volumio[19706]: *** WARNING *** For more information see Jan 25 12:33:01 music node[19706]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 25 12:33:01 music node[19706]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 25 12:33:01 music node[19706]: *** WARNING *** For more information see Jan 25 12:33:01 music node[19706]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 25 12:33:01 music node[19706]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 25 12:33:01 music node[19706]: *** WARNING *** For more information see Jan 25 12:33:01 music volumio[19706]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 25 12:33:01 music volumio[19706]: info: Discovery: Started advertising with name: music Jan 25 12:33:01 music volumio[19706]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 25 12:33:01 music volumio[19706]: info: Loading plugin "spop"... Jan 25 12:33:02 music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Jan 25 12:33:02 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 25 12:33:02 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 25 12:33:02 music go-librespot[19769]: go-librespot daemon starting... Jan 25 12:33:02 music go-librespot[19770]: time="2026-01-25T12:33:02-05:00" level=info msg="running go-librespot 0.6.2" Jan 25 12:33:02 music go-librespot[19770]: time="2026-01-25T12:33:02-05:00" level=debug msg="app state loaded" Jan 25 12:33:02 music go-librespot[19770]: time="2026-01-25T12:33:02-05:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 25 12:33:02 music volumio[19706]: info: Loading plugin "outputs"... Jan 25 12:33:02 music volumio[19706]: info: Loading plugin "albumart"... Jan 25 12:33:02 music volumio[19706]: info: Plugin example_plugin is not enabled Jan 25 12:33:02 music volumio[19706]: info: Loading plugin "inputs"... Jan 25 12:33:02 music volumio[19706]: info: Loading plugin "updater_comm"... Jan 25 12:33:02 music volumio[19706]: info: Plugin mpdemulation is not enabled Jan 25 12:33:02 music volumio[19706]: info: Loading plugin "rest_api"... Jan 25 12:33:02 music volumio[19706]: info: Loading plugin "websocket"... Jan 25 12:33:02 music go-librespot[19770]: time="2026-01-25T12:33:02-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 25 12:33:02 music go-librespot[19770]: time="2026-01-25T12:33:02-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 25 12:33:02 music go-librespot[19770]: time="2026-01-25T12:33:02-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 25 12:33:02 music volumio[19706]: info: Starting Socket.io Server version 1.7.4 Jan 25 12:33:02 music go-librespot[19770]: time="2026-01-25T12:33:02-05:00" level=info msg="zeroconf server listening on port 44075" Jan 25 12:33:02 music volumio[19706]: info: Loading i18n strings for locale en Jan 25 12:33:02 music volumio[19706]: Updating browse sources language Jan 25 12:33:02 music volumio[19706]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 25 12:33:02 music go-librespot[19770]: time="2026-01-25T12:33:02-05:00" level=debug msg="obtained new client token: AABJTRDJHVPHcAUBiFRwd3dBOnuorlhVUuFfsLMXBAX+sPN5vXgv6UXUoYMnr+IJdPI7I8amuD2YhwbcVGgOmTg0Rt16AS4vt0w1dRUmsSgi107svy+C+6WKRzPyf0LSiQhjzEpuKmSoyjUGmAQjJqUYY4ypC9znCFhj2DvUjjg5SwSyolVsd+t/8CNR3f1tw6xLLPN5cr84dgcrygw4S62D+cllBvGCOkoPCiJHzh3VrYP+M5G3CkE=" Jan 25 12:33:02 music volumio[19706]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 25 12:33:02 music volumio[19706]: info: CoreCommandRouter::initPlayerControls Jan 25 12:33:02 music volumio[19706]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:33:02 music volumio[19706]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:33:02 music volumio[19706]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:33:02 music volumio[19706]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:33:02 music volumio[19706]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:33:02 music volumio[19706]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:33:02 music volumio[19706]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:33:02 music volumio[19706]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:33:02 music volumio[19706]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 25 12:33:02 music volumio[19706]: Express server listening on port 3000 Jan 25 12:33:02 music volumio[19706]: [Metrics] WebUI: 6s 690.58ms Jan 25 12:33:02 music go-librespot[19770]: time="2026-01-25T12:33:02-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Jan 25 12:33:02 music volumio[19706]: info: CoreStateMachine::resetVolumioState Jan 25 12:33:02 music volumio[19706]: info: CoreStateMachine::getcurrentVolume Jan 25 12:33:02 music volumio[19706]: info: CoreCommandRouter::volumioRetrievevolume Jan 25 12:33:02 music volumio[19706]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 12:33:02 music go-librespot[19770]: time="2026-01-25T12:33:02-05:00" level=debug msg="completed keyexchange" Jan 25 12:33:02 music go-librespot[19770]: time="2026-01-25T12:33:02-05:00" level=debug msg="completed challenge" Jan 25 12:33:02 music volumio[19706]: info: Volumio Network Manager: Network status updated: 1 Jan 25 12:33:02 music go-librespot[19770]: time="2026-01-25T12:33:02-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 25 12:33:02 music volumio[19778]: Forking 3 albumart workers Jan 25 12:33:02 music volumio-remote-updater[1248]: [2026-01-25 12:33:02] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1769362379 101 Jan 25 12:33:03 music volumio[19706]: 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 25 12:33:03 music volumio[19706]: info: VolumeController:: Volume=86 Mute =false Jan 25 12:33:03 music volumio[19706]: info: CoreStateMachine::pushState Jan 25 12:33:03 music volumio[19706]: info: CorePlayQueue::getTrack 0 Jan 25 12:33:03 music volumio[19706]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 25 12:33:03 music volumio[19706]: info: CoreCommandRouter::volumioPushState Jan 25 12:33:03 music volumio[19706]: info: CoreStateMachine::updateTrackBlock Jan 25 12:33:03 music volumio[19706]: info: CorePlayQueue::getTrackBlock Jan 25 12:33:03 music volumio[19706]: info: CoreCommandRouter::volumioRetrievevolume Jan 25 12:33:03 music volumio[19706]: info: Reloading queue from file Jan 25 12:33:03 music volumio[19706]: info: CoreCommandRouter::volumioGetState Jan 25 12:33:03 music volumio[19706]: info: CorePlayQueue::getTrack 0 Jan 25 12:33:03 music volumio[19706]: info: CoreStateMachine::setRepeat null single undefined Jan 25 12:33:03 music volumio[19706]: info: CoreStateMachine::pushState Jan 25 12:33:03 music volumio[19706]: info: CorePlayQueue::getTrack 0 Jan 25 12:33:03 music volumio[19706]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 25 12:33:03 music volumio[19706]: info: CoreCommandRouter::volumioPushState Jan 25 12:33:03 music volumio[19706]: info: CoreStateMachine::setRandom null Jan 25 12:33:03 music volumio[19706]: info: CoreStateMachine::pushState Jan 25 12:33:03 music volumio[19706]: info: CorePlayQueue::getTrack 0 Jan 25 12:33:03 music volumio[19706]: info: CoreCommandRouter::volumioPushState Jan 25 12:33:03 music volumio[19706]: info: Setting Device type: Raspberry PI Jan 25 12:33:03 music volumio[19706]: info: VolumeController:: Volume=86 Mute =false Jan 25 12:33:03 music volumio[19706]: info: CoreStateMachine::pushState Jan 25 12:33:03 music volumio[19706]: info: CorePlayQueue::getTrack 0 Jan 25 12:33:03 music volumio[19706]: info: CoreCommandRouter::volumioPushState Jan 25 12:33:03 music volumio[19706]: info: Completed loading Core Plugins Jan 25 12:33:03 music volumio[19706]: info: Preparing to generate the ALSA configuration file Jan 25 12:33:03 music volumio[19706]: info: Discovery: adding 4a29b7a7-c637-4926-a2bd-fb4e2f55145e Jan 25 12:33:03 music volumio[19706]: info: Discovery: Found device music Jan 25 12:33:03 music volumio[19706]: info: CoreCommandRouter::volumioGetState Jan 25 12:33:03 music volumio[19706]: info: CorePlayQueue::getTrack 0 Jan 25 12:33:03 music volumio[19706]: info: Discovery: this is already registered, 4a29b7a7-c637-4926-a2bd-fb4e2f55145e Jan 25 12:33:03 music volumio[19706]: info: Discovery: Found device music Jan 25 12:33:03 music volumio[19706]: info: CoreCommandRouter::volumioGetState Jan 25 12:33:03 music volumio[19706]: info: CorePlayQueue::getTrack 0 Jan 25 12:33:03 music volumio[19706]: info: Asound.conf file unchanged, so no further update is needed Jan 25 12:33:03 music volumio[19706]: info: Output device has changed, restarting MPD Jan 25 12:33:03 music volumio[19706]: info: Output device has changed, restarting Shairport Sync Jan 25 12:33:03 music volumio[19706]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:33:03 music volumio[19706]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 12:33:03 music go-librespot[19770]: time="2026-01-25T12:33:03-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Jan 25 12:33:03 music sudo[19837]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 25 12:33:03 music sudo[19837]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 12:33:03 music sudo[19839]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 25 12:33:03 music sudo[19837]: pam_unix(sudo:session): session closed for user root Jan 25 12:33:03 music sudo[19839]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 12:33:03 music volumio[19706]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 25 12:33:03 music volumio[19706]: info: ___________ START PLUGINS ___________ Jan 25 12:33:03 music volumio[19706]: info: ControllerMpd::onStart: Initializing MPD Jan 25 12:33:03 music volumio[19706]: info: Creating MPD Configuration file Jan 25 12:33:03 music go-librespot[19770]: time="2026-01-25T12:33:03-05:00" level=debug msg="completed keyexchange" Jan 25 12:33:03 music go-librespot[19770]: time="2026-01-25T12:33:03-05:00" level=debug msg="completed challenge" Jan 25 12:33:03 music systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 25 12:33:03 music sudo[19847]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 25 12:33:03 music sudo[19847]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 12:33:03 music sudo[19847]: pam_unix(sudo:session): session closed for user root Jan 25 12:33:03 music go-librespot[19770]: time="2026-01-25T12:33:03-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 25 12:33:03 music volumio[19706]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 25 12:33:03 music volumio[19706]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 25 12:33:03 music volumio[19706]: info: [1769362383706] CoreMusicLibrary::Adding element Media Servers Jan 25 12:33:03 music volumio[19706]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 25 12:33:03 music sudo[19849]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 25 12:33:03 music systemd[1]: mpd.service: Deactivated successfully. Jan 25 12:33:03 music systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 25 12:33:03 music systemd[1]: mpd.service: Consumed 4.245s CPU time. Jan 25 12:33:03 music systemd[1]: mpd.socket: Deactivated successfully. Jan 25 12:33:03 music sudo[19849]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 12:33:03 music systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 25 12:33:03 music systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 25 12:33:03 music volumio[19706]: info: UPNP Browser: Client initialized successfully Jan 25 12:33:03 music volumio[19706]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:33:03 music volumio[19706]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 12:33:03 music systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 25 12:33:03 music systemd[1]: Starting mpd.service - Music Player Daemon... Jan 25 12:33:03 music volumio[19706]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 25 12:33:03 music volumio[19706]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:33:03 music volumio[19706]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 12:33:03 music volumio[19706]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 25 12:33:03 music volumio[19706]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 25 12:33:03 music volumio[19706]: info: [1769362383876] CoreMusicLibrary::Adding element Last_100 Jan 25 12:33:03 music volumio[19706]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 25 12:33:03 music systemd[1]: mpd.service: Deactivated successfully. Jan 25 12:33:03 music systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 25 12:33:03 music volumio[19706]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 25 12:33:03 music volumio[19706]: info: [1769362383897] CoreMusicLibrary::Adding element Webradio Jan 25 12:33:03 music volumio[19706]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 25 12:33:03 music systemd[1]: mpd.socket: Deactivated successfully. Jan 25 12:33:03 music systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 25 12:33:03 music systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 25 12:33:03 music volumio[19706]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 25 12:33:03 music volumio[19706]: info: Initializing BBC Radios Jan 25 12:33:03 music systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 25 12:33:03 music volumio[19706]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 25 12:33:03 music volumio[19706]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 12:33:03 music systemd[1]: Starting mpd.service - Music Player Daemon... Jan 25 12:33:04 music volumio[19706]: info: Creating Spotify config file Jan 25 12:33:04 music volumio[19706]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:33:04 music sudo[19876]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 25 12:33:04 music sudo[19876]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 25 12:33:04 music go-librespot[19770]: time="2026-01-25T12:33:04-05:00" level=debug msg="connected to ap-gue1.spotify.com:80" Jan 25 12:33:04 music sudo[19876]: pam_unix(sudo:session): session closed for user root Jan 25 12:33:04 music go-librespot[19770]: time="2026-01-25T12:33:04-05:00" level=debug msg="completed keyexchange" Jan 25 12:33:04 music go-librespot[19770]: time="2026-01-25T12:33:04-05:00" level=debug msg="completed challenge" Jan 25 12:33:04 music go-librespot[19770]: time="2026-01-25T12:33:04-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 25 12:33:04 music volumio[19706]: info: Volumio Calling Home Jan 25 12:33:04 music volumio[19795]: Starting albumart workers Jan 25 12:33:04 music volumio[19706]: info: MPD Permissions set Jan 25 12:33:04 music volumio[19706]: info: MPD Permissions set Jan 25 12:33:04 music volumio[19797]: Starting albumart workers Jan 25 12:33:04 music go-librespot[19770]: time="2026-01-25T12:33:04-05:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 25 12:33:05 music volumio[19706]: 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 25 12:33:05 music volumio[19706]: info: Volumio called home Jan 25 12:33:05 music volumio[19706]: info: Spotify config file written Jan 25 12:33:05 music sudo[19883]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 25 12:33:05 music go-librespot[19770]: time="2026-01-25T12:33:05-05:00" level=debug msg="completed keyexchange" Jan 25 12:33:05 music go-librespot[19770]: time="2026-01-25T12:33:05-05:00" level=debug msg="completed challenge" Jan 25 12:33:05 music sudo[19883]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 12:33:05 music go-librespot[19770]: time="2026-01-25T12:33:05-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 25 12:33:05 music volumio[19796]: Starting albumart workers Jan 25 12:33:05 music systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Jan 25 12:33:05 music systemd[1]: go-librespot-daemon.service: Deactivated successfully. Jan 25 12:33:05 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 25 12:33:05 music volumio[19706]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:33:05 music volumio[19706]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:33:05 music volumio[19706]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:33:05 music volumio[19706]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:33:05 music volumio[19706]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:33:05 music volumio[19706]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:33:05 music volumio[19706]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:33:05 music volumio[19706]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:33:05 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 25 12:33:05 music go-librespot[19885]: go-librespot daemon starting... Jan 25 12:33:05 music sudo[19883]: pam_unix(sudo:session): session closed for user root Jan 25 12:33:05 music go-librespot[19886]: time="2026-01-25T12:33:05-05:00" level=info msg="running go-librespot 0.6.2" Jan 25 12:33:05 music go-librespot[19886]: time="2026-01-25T12:33:05-05:00" level=debug msg="app state loaded" Jan 25 12:33:05 music go-librespot[19886]: time="2026-01-25T12:33:05-05:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 25 12:33:05 music volumio[19706]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 12:33:05 music volumio[19706]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:33:05 music volumio[19706]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:33:05 music volumio[19706]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:33:05 music volumio[19706]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:33:05 music volumio[19706]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:33:05 music volumio[19706]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:33:05 music volumio[19706]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:33:05 music volumio[19706]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:33:05 music volumio[19706]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:33:05 music volumio[19706]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 12:33:05 music volumio[19706]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:33:05 music volumio[19706]: info: No need to fix Spotify hosts Jan 25 12:33:05 music go-librespot[19886]: time="2026-01-25T12:33:05-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 25 12:33:05 music go-librespot[19886]: time="2026-01-25T12:33:05-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 25 12:33:05 music go-librespot[19886]: time="2026-01-25T12:33:05-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 25 12:33:05 music go-librespot[19886]: time="2026-01-25T12:33:05-05:00" level=info msg="zeroconf server listening on port 41801" Jan 25 12:33:05 music volumio[19706]: info: Starting Shairport Sync Jan 25 12:33:05 music go-librespot[19886]: time="2026-01-25T12:33:05-05:00" level=debug msg="obtained new client token: AABXHhGbCjuaTjLUTrnmWKzxzhPDDf3pnEkHfYzHVB2sTjZ6GuuN5cDeL/QAW1m8f4kMuJMTqq1y9JorK1FoC9YccRx1aNOv4YjWifyKUgoCx9nUmHH7EjdvWFfAnxh6TmYW3aNObCdBXias+1mrItGOy19iDVGFxETvaNhQcBADMZdVoRn///mZ3O414OKhKjdERvS8BOhPwRn8f4szXdl0OXyv6tY35WQ7m1q/VsOTGAYIa6I7fSc=" Jan 25 12:33:06 music volumio[19706]: info: Starting Shairport Sync Jan 25 12:33:06 music volumio[19706]: info: Starting Shairport Sync Jan 25 12:33:06 music go-librespot[19886]: time="2026-01-25T12:33:06-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Jan 25 12:33:06 music sudo[19907]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 25 12:33:06 music sudo[19907]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 12:33:06 music sudo[19908]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 25 12:33:06 music sudo[19908]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 12:33:06 music volumio[19706]: info: An error occurred while refreshing Spotify Token Error: Bad Request Jan 25 12:33:06 music go-librespot[19886]: time="2026-01-25T12:33:06-05:00" level=debug msg="completed keyexchange" Jan 25 12:33:06 music go-librespot[19886]: time="2026-01-25T12:33:06-05:00" level=debug msg="completed challenge" Jan 25 12:33:06 music sudo[19911]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 25 12:33:06 music sudo[19911]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 12:33:06 music go-librespot[19886]: time="2026-01-25T12:33:06-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 25 12:33:06 music systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 25 12:33:06 music systemd[1]: shairport-sync.service: Deactivated successfully. Jan 25 12:33:06 music systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 25 12:33:06 music systemd[1]: shairport-sync.service: Consumed 1.871s CPU time. Jan 25 12:33:06 music systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 25 12:33:06 music sudo[19907]: pam_unix(sudo:session): session closed for user root Jan 25 12:33:06 music sudo[19908]: pam_unix(sudo:session): session closed for user root Jan 25 12:33:06 music systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 25 12:33:06 music systemd[1]: shairport-sync.service: Deactivated successfully. Jan 25 12:33:06 music systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 25 12:33:06 music systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 25 12:33:06 music sudo[19911]: pam_unix(sudo:session): session closed for user root Jan 25 12:33:06 music volumio[19706]: info: Shairport-Sync Started Jan 25 12:33:06 music volumio[19706]: Error adding Membership: Error: addMembership EINVAL Jan 25 12:33:06 music volumio[19706]: info: Shairport-Sync Started Jan 25 12:33:06 music volumio[19706]: info: Shairport-Sync Started Jan 25 12:33:06 music volumio[19706]: info: CoreCommandRouter::volumioGetState Jan 25 12:33:06 music volumio[19706]: info: CorePlayQueue::getTrack 0 Jan 25 12:33:06 music go-librespot[19886]: time="2026-01-25T12:33:06-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Jan 25 12:33:06 music go-librespot[19886]: time="2026-01-25T12:33:06-05:00" level=debug msg="completed keyexchange" Jan 25 12:33:06 music go-librespot[19886]: time="2026-01-25T12:33:06-05:00" level=debug msg="completed challenge" Jan 25 12:33:06 music go-librespot[19886]: time="2026-01-25T12:33:06-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 25 12:33:07 music go-librespot[19886]: time="2026-01-25T12:33:07-05:00" level=debug msg="connected to ap-gue1.spotify.com:80" Jan 25 12:33:07 music go-librespot[19886]: time="2026-01-25T12:33:07-05:00" level=debug msg="completed keyexchange" Jan 25 12:33:07 music go-librespot[19886]: time="2026-01-25T12:33:07-05:00" level=debug msg="completed challenge" Jan 25 12:33:07 music go-librespot[19886]: time="2026-01-25T12:33:07-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 25 12:33:08 music go-librespot[19886]: time="2026-01-25T12:33:08-05:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 25 12:33:08 music go-librespot[19886]: time="2026-01-25T12:33:08-05:00" level=debug msg="completed keyexchange" Jan 25 12:33:08 music go-librespot[19886]: time="2026-01-25T12:33:08-05:00" level=debug msg="completed challenge" Jan 25 12:33:08 music go-librespot[19886]: time="2026-01-25T12:33:08-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 25 12:33:08 music mpd[19878]: 2026-01-25T12:33:08 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 25 12:33:08 music systemd[1]: Started mpd.service - Music Player Daemon. Jan 25 12:33:08 music sudo[19839]: pam_unix(sudo:session): session closed for user root Jan 25 12:33:08 music sudo[19849]: pam_unix(sudo:session): session closed for user root Jan 25 12:33:08 music volumio[19706]: info: Completed starting Core Plugins Jan 25 12:33:08 music volumio[19706]: info: ------------------------------------------- Jan 25 12:33:08 music volumio[19706]: info: ----- MyVolumio plugins startup ---- Jan 25 12:33:08 music volumio[19706]: info: ------------------------------------------- Jan 25 12:33:08 music volumio[19706]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 25 12:33:08 music volumio[19706]: error: MPD error: The expression evaluated to a falsy value: Jan 25 12:33:08 music volumio[19706]: assert.ok(self.idling) Jan 25 12:33:08 music volumio[19706]: error: The expression evaluated to a falsy value: Jan 25 12:33:08 music volumio[19706]: assert.ok(self.idling) Jan 25 12:33:08 music volumio[19706]: info: MPD running with PID19878 Jan 25 12:33:08 music volumio[19706]: ,establishing connection Jan 25 12:33:08 music volumio[19706]: error: updateQueue error: null Jan 25 12:33:08 music volumio[19706]: error: updateQueue error: null Jan 25 12:33:08 music go-librespot[19886]: time="2026-01-25T12:33:08-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 25 12:33:08 music volumio[19706]: info: go-librespot daemon successfully initialized Jan 25 12:33:08 music sudo[19980]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 25 12:33:08 music sudo[19980]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 12:33:08 music sudo[19982]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 25 12:33:08 music sudo[19980]: pam_unix(sudo:session): session closed for user root Jan 25 12:33:08 music sudo[19982]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 12:33:08 music sudo[19982]: pam_unix(sudo:session): session closed for user root Jan 25 12:33:08 music sudo[19986]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 25 12:33:08 music sudo[19986]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 12:33:09 music go-librespot[19886]: time="2026-01-25T12:33:09-05:00" level=debug msg="connected to ap-gew4.spotify.com:80" Jan 25 12:33:09 music sudo[19986]: pam_unix(sudo:session): session closed for user root Jan 25 12:33:09 music volumio[19706]: info: Upmpdcli Daemon Started Jan 25 12:33:09 music go-librespot[19886]: time="2026-01-25T12:33:09-05:00" level=debug msg="completed keyexchange" Jan 25 12:33:09 music go-librespot[19886]: time="2026-01-25T12:33:09-05:00" level=debug msg="completed challenge" Jan 25 12:33:09 music go-librespot[19886]: time="2026-01-25T12:33:09-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 25 12:33:09 music go-librespot[19886]: time="2026-01-25T12:33:09-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Jan 25 12:33:09 music go-librespot[19886]: time="2026-01-25T12:33:09-05:00" level=debug msg="completed keyexchange" Jan 25 12:33:09 music go-librespot[19886]: time="2026-01-25T12:33:09-05:00" level=debug msg="completed challenge" Jan 25 12:33:09 music volumio[19706]: info: CoreCommandRouter::volumioGetState Jan 25 12:33:09 music volumio[19706]: info: CorePlayQueue::getTrack 0 Jan 25 12:33:09 music volumio[19706]: info: Listing playlists Jan 25 12:33:09 music volumio[19706]: info: Listing playlists Jan 25 12:33:09 music go-librespot[19886]: time="2026-01-25T12:33:09-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 25 12:33:09 music go-librespot[19886]: time="2026-01-25T12:33:09-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 25 12:33:09 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 25 12:33:09 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 25 12:33:11 music sudo[19989]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Jan 25 12:33:11 music sudo[19989]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 12:33:11 music sudo[19991]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Jan 25 12:33:11 music sudo[19991]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 12:33:11 music systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Jan 25 12:33:11 music systemd[1]: mpd_monitor.service: Deactivated successfully. Jan 25 12:33:11 music systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Jan 25 12:33:11 music systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Jan 25 12:33:11 music sudo[19991]: pam_unix(sudo:session): session closed for user root Jan 25 12:33:11 music sudo[19989]: pam_unix(sudo:session): session closed for user root Jan 25 12:33:11 music mpd_monitor.sh[19994]: MPD Monitor Service: Starting MPD Monitor Service Jan 25 12:33:11 music volumio[19706]: info: Successfully started MPD Monitor Jan 25 12:33:11 music volumio[19706]: info: Successfully started MPD Monitor Jan 25 12:33:11 music volumio[19706]: info: Initializing connection to go-librespot Websocket Jan 25 12:33:11 music volumio[19706]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 25 12:33:13 music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Jan 25 12:33:13 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 25 12:33:13 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 25 12:33:13 music go-librespot[19998]: go-librespot daemon starting... Jan 25 12:33:13 music go-librespot[19999]: time="2026-01-25T12:33:13-05:00" level=info msg="running go-librespot 0.6.2" Jan 25 12:33:13 music go-librespot[19999]: time="2026-01-25T12:33:13-05:00" level=debug msg="app state loaded" Jan 25 12:33:13 music go-librespot[19999]: time="2026-01-25T12:33:13-05:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 25 12:33:13 music volumio[19706]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 25 12:33:13 music go-librespot[19999]: time="2026-01-25T12:33:13-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 25 12:33:13 music go-librespot[19999]: time="2026-01-25T12:33:13-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 25 12:33:13 music go-librespot[19999]: time="2026-01-25T12:33:13-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 25 12:33:13 music go-librespot[19999]: time="2026-01-25T12:33:13-05:00" level=info msg="zeroconf server listening on port 34813" Jan 25 12:33:13 music go-librespot[19999]: time="2026-01-25T12:33:13-05:00" level=debug msg="obtained new client token: AADwpaPuk/qfCD9nbbE/mb5sWexOj6hGA3yIWtsEvBaigcpBM2cdX++NJifthLJAOIbrDo7gy3seJk3BiLkeoHdDtGEoYZeXKpe3ydVrGaeTomAE6UBoO8YIufkH7rGM2M6nXZdAMkobbRAkbgONYiPmtbRrHAKDbC3jvp+Bl4LMe6a3vww1nHm45x+1iXnnFgHFSeJtwzNpDrVA05io/6OQZtbn6Z/cdAtmtmE18wZPsy9OVu/QQ8U=" Jan 25 12:33:13 music go-librespot[19999]: time="2026-01-25T12:33:13-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Jan 25 12:33:13 music go-librespot[19999]: time="2026-01-25T12:33:13-05:00" level=debug msg="completed keyexchange" Jan 25 12:33:13 music go-librespot[19999]: time="2026-01-25T12:33:13-05:00" level=debug msg="completed challenge" Jan 25 12:33:13 music go-librespot[19999]: time="2026-01-25T12:33:13-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 25 12:33:14 music go-librespot[19999]: time="2026-01-25T12:33:14-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Jan 25 12:33:14 music go-librespot[19999]: time="2026-01-25T12:33:14-05:00" level=debug msg="completed keyexchange" Jan 25 12:33:14 music go-librespot[19999]: time="2026-01-25T12:33:14-05:00" level=debug msg="completed challenge" Jan 25 12:33:14 music go-librespot[19999]: time="2026-01-25T12:33:14-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 25 12:33:14 music volumio[19706]: info: Initializing connection to go-librespot Websocket Jan 25 12:33:14 music go-librespot[19999]: time="2026-01-25T12:33:14-05:00" level=debug msg="new websocket client" Jan 25 12:33:14 music volumio[19706]: info: Connection to go-librespot Websocket established Jan 25 12:33:15 music go-librespot[19999]: time="2026-01-25T12:33:15-05:00" level=debug msg="connected to ap-gue1.spotify.com:80" Jan 25 12:33:15 music go-librespot[19999]: time="2026-01-25T12:33:15-05:00" level=debug msg="completed keyexchange" Jan 25 12:33:15 music go-librespot[19999]: time="2026-01-25T12:33:15-05:00" level=debug msg="completed challenge" Jan 25 12:33:15 music go-librespot[19999]: time="2026-01-25T12:33:15-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 25 12:33:15 music go-librespot[19999]: time="2026-01-25T12:33:15-05:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 25 12:33:16 music go-librespot[19999]: time="2026-01-25T12:33:16-05:00" level=debug msg="completed keyexchange" Jan 25 12:33:16 music go-librespot[19999]: time="2026-01-25T12:33:16-05:00" level=debug msg="completed challenge" Jan 25 12:33:16 music go-librespot[19999]: time="2026-01-25T12:33:16-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 25 12:33:16 music volumio[19706]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 25 12:33:16 music volumio[19706]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 25 12:33:16 music volumio[19706]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 25 12:33:16 music volumio[19706]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jan 25 12:33:16 music volumio[19706]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 25 12:33:16 music volumio[19706]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 25 12:33:16 music volumio[19706]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 25 12:33:16 music volumio[19706]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 25 12:33:16 music volumio[19706]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 25 12:33:16 music volumio[19706]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 25 12:33:16 music volumio[19706]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jan 25 12:33:16 music volumio[19706]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 25 12:33:16 music volumio[19706]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 25 12:33:16 music volumio[19706]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 25 12:33:16 music volumio[19706]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jan 25 12:33:16 music volumio[19706]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 25 12:33:16 music volumio[19706]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 25 12:33:16 music volumio[19706]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 25 12:33:16 music volumio[19706]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 25 12:33:16 music volumio[19706]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 25 12:33:16 music volumio[19706]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 25 12:33:16 music volumio[19706]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jan 25 12:33:16 music volumio[19706]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 25 12:33:16 music volumio[19706]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jan 25 12:33:16 music volumio[19706]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 25 12:33:16 music volumio[19706]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 25 12:33:16 music volumio[19706]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 25 12:33:16 music volumio[19706]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 25 12:33:16 music volumio[19706]: info: Adding plugin bluetooth to MyMusic Plugins Jan 25 12:33:16 music volumio[19706]: info: Adding plugin multiroom to MyMusic Plugins Jan 25 12:33:16 music volumio[19706]: info: Adding plugin metavolumio to MyMusic Plugins Jan 25 12:33:16 music volumio[19706]: info: Adding plugin cd_controller to MyMusic Plugins Jan 25 12:33:16 music volumio[19706]: info: Adding plugin qobuzconnect to MyMusic Plugins Jan 25 12:33:16 music volumio[19706]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 25 12:33:16 music volumio[19706]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 25 12:33:16 music volumio[19706]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 25 12:33:17 music go-librespot[19999]: time="2026-01-25T12:33:17-05:00" level=debug msg="connected to ap-gew1.spotify.com:443" Jan 25 12:33:17 music go-librespot[19999]: time="2026-01-25T12:33:17-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 25 12:33:17 music go-librespot[19999]: time="2026-01-25T12:33:17-05:00" level=debug msg="connected to ap-gew4.spotify.com:80" Jan 25 12:33:17 music volumio[19706]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 25 12:33:17 music volumio[19706]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 25 12:33:17 music volumio[19706]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 12:33:17 music volumio[19706]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 12:33:17 music volumio[19706]: info: Starting MyVolumio Remote Streaming Endpoints Jan 25 12:33:17 music volumio[19706]: info: MyVolumio login type: Token Jan 25 12:33:17 music volumio[19706]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 25 12:33:17 music volumio[19706]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 25 12:33:18 music go-librespot[19999]: time="2026-01-25T12:33:18-05:00" level=debug msg="completed keyexchange" Jan 25 12:33:18 music go-librespot[19999]: time="2026-01-25T12:33:18-05:00" level=debug msg="completed challenge" Jan 25 12:33:18 music go-librespot[19999]: time="2026-01-25T12:33:18-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 25 12:33:18 music go-librespot[19999]: time="2026-01-25T12:33:18-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 25 12:33:18 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 25 12:33:18 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 25 12:33:18 music volumio[19706]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 25 12:33:18 music volumio[19706]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 25 12:33:18 music volumio[19706]: info: Streaming services startup Jan 25 12:33:18 music volumio[19706]: info: Starting Streaming Daemon Jan 25 12:33:18 music sudo[20009]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 25 12:33:18 music sudo[20009]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 12:33:18 music volumio[19706]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 25 12:33:18 music sudo[20009]: pam_unix(sudo:session): session closed for user root Jan 25 12:33:18 music volumio[19706]: info: Getting Spotify volume Jan 25 12:33:18 music volumio[19706]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 25 12:33:18 music volumio[19706]: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 25 12:33:18 music volumio[19706]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Jan 25 12:33:18 music volumio[19706]: errno: -111, Jan 25 12:33:18 music volumio[19706]: code: 'ECONNREFUSED', Jan 25 12:33:18 music volumio[19706]: syscall: 'connect', Jan 25 12:33:18 music volumio[19706]: address: '127.0.0.1', Jan 25 12:33:18 music volumio[19706]: port: 9879, Jan 25 12:33:18 music volumio[19706]: response: undefined Jan 25 12:33:18 music volumio[19706]: } Jan 25 12:33:18 music volumio[19706]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 25 12:33:19 music sudo[20044]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-25 12:32' Jan 25 12:33:19 music sudo[20044]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 12:33:19 music sudo[20044]: pam_unix(sudo:session): session closed for user root Jan 25 12:33:20 music volumio-remote-updater[1248]: [2026-01-25 12:33:20] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Jan 25 12:33:20 music volumio-remote-updater[1248]: [2026-01-25 12:33:20] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Jan 25 12:33:20 music systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 25 12:33:20 music systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 25 12:33:20 music systemd[1]: volumio.service: Consumed 26.517s CPU time. Jan 25 12:33:20 music systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 25 12:33:20 music systemd[1]: dynamicswap.service: Deactivated successfully. Jan 25 12:33:21 music systemd[1]: volumio.service: Scheduled restart job, restart counter is at 27813. Jan 25 12:33:21 music systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 25 12:33:21 music systemd[1]: Stopped volumio.service - Volumio Backend Module. Jan 25 12:33:21 music systemd[1]: volumio.service: Consumed 26.517s CPU time. Jan 25 12:33:21 music systemd[1]: Started volumio.service - Volumio Backend Module. Jan 25 12:33:21 music systemd[1]: dynamicswap.service: Deactivated successfully. Jan 25 12:33:21 music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Jan 25 12:33:21 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 25 12:33:21 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 25 12:33:21 music go-librespot[20074]: go-librespot daemon starting... Jan 25 12:33:21 music go-librespot[20075]: time="2026-01-25T12:33:21-05:00" level=info msg="running go-librespot 0.6.2" Jan 25 12:33:21 music go-librespot[20075]: time="2026-01-25T12:33:21-05:00" level=debug msg="app state loaded" Jan 25 12:33:21 music go-librespot[20075]: time="2026-01-25T12:33:21-05:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 25 12:33:21 music go-librespot[20075]: time="2026-01-25T12:33:21-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 25 12:33:21 music go-librespot[20075]: time="2026-01-25T12:33:21-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 25 12:33:21 music go-librespot[20075]: time="2026-01-25T12:33:21-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 25 12:33:21 music go-librespot[20075]: time="2026-01-25T12:33:21-05:00" level=info msg="zeroconf server listening on port 37211" Jan 25 12:33:21 music go-librespot[20075]: time="2026-01-25T12:33:21-05:00" level=debug msg="obtained new client token: AACRXOvH8yb7wb1mNN3W6ETx20M0JyBRSLDwq5CbGiddJH+mCxccFxZDn4Lmp6zxHHaY7832j+b+Ut0Mfih4WbPbpusEi5t4TwaHGwvvR8U8Wvd4DS/klUL3G5fp4L/UPXPgAthyNVOMjJ83pxK0kW4YwGzq4crQcvISsVw+6eW75rKJV50ayUL05+JwG8C34eb/sNd7U78nMMIoMR8ab9YKGCQT+DcIbkGsimA+kTvhrWQNuBh/vzM=" Jan 25 12:33:22 music go-librespot[20075]: time="2026-01-25T12:33:22-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Jan 25 12:33:22 music go-librespot[20075]: time="2026-01-25T12:33:22-05:00" level=debug msg="completed keyexchange" Jan 25 12:33:22 music go-librespot[20075]: time="2026-01-25T12:33:22-05:00" level=debug msg="completed challenge" Jan 25 12:33:22 music go-librespot[20075]: time="2026-01-25T12:33:22-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 25 12:33:22 music go-librespot[20075]: time="2026-01-25T12:33:22-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Jan 25 12:33:22 music go-librespot[20075]: time="2026-01-25T12:33:22-05:00" level=debug msg="completed keyexchange" Jan 25 12:33:22 music go-librespot[20075]: time="2026-01-25T12:33:22-05:00" level=debug msg="completed challenge" Jan 25 12:33:22 music go-librespot[20075]: time="2026-01-25T12:33:22-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 25 12:33:23 music volumio[20059]: info: ------------------------------------------- Jan 25 12:33:23 music volumio[20059]: info: ----- Volumio3 ---- Jan 25 12:33:23 music volumio[20059]: info: ------------------------------------------- Jan 25 12:33:23 music volumio[20059]: info: ----- System startup ---- Jan 25 12:33:23 music volumio[20059]: info: ------------------------------------------- Jan 25 12:33:23 music go-librespot[20075]: time="2026-01-25T12:33:23-05:00" level=debug msg="connected to ap-gue1.spotify.com:80" Jan 25 12:33:23 music go-librespot[20075]: time="2026-01-25T12:33:23-05:00" level=debug msg="completed keyexchange" Jan 25 12:33:23 music go-librespot[20075]: time="2026-01-25T12:33:23-05:00" level=debug msg="completed challenge" Jan 25 12:33:23 music go-librespot[20075]: time="2026-01-25T12:33:23-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 25 12:33:23 music volumio[20059]: info: MYVOLUMIO Environment detected Jan 25 12:33:23 music volumio[20059]: info: Plugin folders cleanup Jan 25 12:33:23 music volumio[20059]: info: Scanning into folder /volumio/app/plugins/ Jan 25 12:33:23 music volumio[20059]: info: Scanning category audio_interface Jan 25 12:33:23 music volumio[20059]: info: Scanning category miscellanea Jan 25 12:33:23 music volumio[20059]: info: Scanning category music_service Jan 25 12:33:23 music volumio[20059]: info: Scanning category plugins.json Jan 25 12:33:23 music volumio[20059]: info: Scanning category system_controller Jan 25 12:33:23 music volumio[20059]: info: Scanning category user_interface Jan 25 12:33:23 music volumio[20059]: info: Scanning into folder /data/plugins/ Jan 25 12:33:23 music volumio[20059]: info: Scanning category music_service Jan 25 12:33:23 music volumio[20059]: info: Plugin folders cleanup completed Jan 25 12:33:23 music volumio[20059]: info: ------------------------------------------- Jan 25 12:33:23 music volumio[20059]: info: ----- Core plugins startup ---- Jan 25 12:33:23 music volumio[20059]: info: ------------------------------------------- Jan 25 12:33:24 music volumio[20059]: info: Loading plugins from folder /volumio/app/plugins/ Jan 25 12:33:24 music volumio[20059]: info: Adding plugin upnp to MyMusic Plugins Jan 25 12:33:24 music volumio[20059]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 25 12:33:24 music volumio[20059]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 25 12:33:24 music volumio[20059]: info: Loading plugins from folder /data/plugins/ Jan 25 12:33:24 music volumio[20059]: info: Loading plugin "system"... Jan 25 12:33:24 music volumio[20059]: info: Loading plugin "appearance"... Jan 25 12:33:24 music go-librespot[20075]: time="2026-01-25T12:33:24-05:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 25 12:33:24 music go-librespot[20075]: time="2026-01-25T12:33:24-05:00" level=debug msg="completed keyexchange" Jan 25 12:33:24 music go-librespot[20075]: time="2026-01-25T12:33:24-05:00" level=debug msg="completed challenge" Jan 25 12:33:24 music go-librespot[20075]: time="2026-01-25T12:33:24-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 25 12:33:25 music go-librespot[20075]: time="2026-01-25T12:33:25-05:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 25 12:33:25 music volumio[20059]: info: Loading plugin "network"... Jan 25 12:33:25 music volumio[20059]: info: Refreshing Cached IP Addresses Jan 25 12:33:25 music sudo[20097]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 25 12:33:25 music sudo[20097]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 12:33:25 music sudo[20099]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 25 12:33:25 music sudo[20099]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 12:33:25 music sudo[20097]: pam_unix(sudo:session): session closed for user root Jan 25 12:33:25 music sudo[20099]: pam_unix(sudo:session): session closed for user root Jan 25 12:33:25 music volumio[20059]: info: Loading plugin "services"... Jan 25 12:33:25 music volumio[20059]: info: Loading plugin "alsa_controller"... Jan 25 12:33:25 music sudo[20107]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 25 12:33:25 music sudo[20107]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 12:33:25 music go-librespot[20075]: time="2026-01-25T12:33:25-05:00" level=debug msg="completed keyexchange" Jan 25 12:33:25 music go-librespot[20075]: time="2026-01-25T12:33:25-05:00" level=debug msg="completed challenge" Jan 25 12:33:25 music volumio[20059]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 25 12:33:25 music volumio[20059]: info: Loading plugin "wizard"... Jan 25 12:33:25 music volumio[20059]: info: Loading plugin "networkfs"... Jan 25 12:33:25 music volumio[20059]: info: Starting Udev Watcher for removable devices Jan 25 12:33:25 music volumio[20059]: info: Ignoring mount for partition: boot Jan 25 12:33:25 music volumio[20059]: info: Ignoring mount for partition: volumio Jan 25 12:33:25 music volumio[20059]: info: Ignoring mount for partition: volumio_data Jan 25 12:33:25 music volumio[20059]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 25 12:33:25 music volumio[20059]: info: Loading plugin "volumio_command_line_client"... Jan 25 12:33:25 music volumio[20059]: info: Loading plugin "upnp"... Jan 25 12:33:25 music volumio[20059]: info: [1769362405380] Starting Upmpd Daemon Jan 25 12:33:25 music volumio[20059]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 25 12:33:25 music volumio[20059]: info: Loading plugin "my_music"... Jan 25 12:33:25 music volumio[20059]: info: Loading plugin "mpd"... Jan 25 12:33:25 music go-librespot[20075]: time="2026-01-25T12:33:25-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 25 12:33:25 music volumio-remote-updater[1248]: [2026-01-25 12:33:25] [connect] Successful connection Jan 25 12:33:25 music volumio[20059]: info: Loading plugin "upnp_browser"... Jan 25 12:33:25 music sudo[20107]: pam_unix(sudo:session): session closed for user root Jan 25 12:33:26 music go-librespot[20075]: time="2026-01-25T12:33:26-05:00" level=debug msg="connected to ap-gew4.spotify.com:80" Jan 25 12:33:26 music go-librespot[20075]: time="2026-01-25T12:33:26-05:00" level=debug msg="completed keyexchange" Jan 25 12:33:26 music go-librespot[20075]: time="2026-01-25T12:33:26-05:00" level=debug msg="completed challenge" Jan 25 12:33:26 music go-librespot[20075]: time="2026-01-25T12:33:26-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 25 12:33:26 music go-librespot[20075]: time="2026-01-25T12:33:26-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 25 12:33:26 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 25 12:33:26 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 25 12:33:27 music volumio[20059]: info: Starting UPNP Browser Jan 25 12:33:27 music volumio[20059]: info: Loading plugin "alarm-clock"... Jan 25 12:33:27 music volumio[20059]: info: Loading plugin "airplay_emulation"... Jan 25 12:33:27 music volumio[20059]: info: Starting Shairport Sync Jan 25 12:33:27 music volumio[20059]: info: Loading plugin "last_100"... Jan 25 12:33:27 music volumio[20059]: info: Loading plugin "webradio"... Jan 25 12:33:27 music volumio[20059]: info: Loading plugin "i2s_dacs"... Jan 25 12:33:27 music volumio[20059]: info: I2S DAC not set, start Auto-detection Jan 25 12:33:27 music volumio[20059]: info: Loading plugin "volumiodiscovery"... Jan 25 12:33:27 music volumio[20059]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 25 12:33:27 music volumio[20059]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 25 12:33:27 music volumio[20059]: *** WARNING *** For more information see Jan 25 12:33:27 music volumio[20059]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 25 12:33:27 music volumio[20059]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 25 12:33:27 music volumio[20059]: *** WARNING *** For more information see Jan 25 12:33:27 music node[20059]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 25 12:33:27 music node[20059]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 25 12:33:27 music node[20059]: *** WARNING *** For more information see Jan 25 12:33:27 music node[20059]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 25 12:33:27 music node[20059]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 25 12:33:27 music node[20059]: *** WARNING *** For more information see Jan 25 12:33:27 music volumio[20059]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 25 12:33:27 music volumio[20059]: info: Discovery: Started advertising with name: music Jan 25 12:33:27 music volumio[20059]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 25 12:33:27 music volumio[20059]: info: Loading plugin "spop"... Jan 25 12:33:28 music volumio[20059]: info: Loading plugin "outputs"... Jan 25 12:33:28 music volumio[20059]: info: Loading plugin "albumart"... Jan 25 12:33:28 music volumio[20059]: info: Plugin example_plugin is not enabled Jan 25 12:33:28 music volumio[20059]: info: Loading plugin "inputs"... Jan 25 12:33:28 music volumio[20059]: info: Loading plugin "updater_comm"... Jan 25 12:33:28 music volumio[20059]: info: Plugin mpdemulation is not enabled Jan 25 12:33:28 music volumio[20059]: info: Loading plugin "rest_api"... Jan 25 12:33:28 music volumio[20059]: info: Loading plugin "websocket"... Jan 25 12:33:28 music volumio[20059]: info: Starting Socket.io Server version 1.7.4 Jan 25 12:33:28 music volumio[20059]: info: Loading i18n strings for locale en Jan 25 12:33:28 music volumio[20059]: Updating browse sources language Jan 25 12:33:28 music volumio[20059]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 25 12:33:29 music volumio[20059]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 25 12:33:29 music volumio[20059]: info: CoreCommandRouter::initPlayerControls Jan 25 12:33:29 music volumio[20059]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:33:29 music volumio[20059]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:33:29 music volumio[20059]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:33:29 music volumio[20059]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:33:29 music volumio[20059]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:33:29 music volumio[20059]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:33:29 music volumio[20059]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:33:29 music volumio[20059]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:33:29 music volumio[20059]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 25 12:33:29 music volumio[20059]: Express server listening on port 3000 Jan 25 12:33:29 music volumio[20059]: [Metrics] WebUI: 6s 537.93ms Jan 25 12:33:29 music volumio[20059]: info: CoreStateMachine::resetVolumioState Jan 25 12:33:29 music volumio[20059]: info: CoreStateMachine::getcurrentVolume Jan 25 12:33:29 music volumio[20059]: info: CoreCommandRouter::volumioRetrievevolume Jan 25 12:33:29 music volumio[20059]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 12:33:29 music volumio[20059]: info: Volumio Network Manager: Network status updated: 1 Jan 25 12:33:29 music volumio-remote-updater[1248]: [2026-01-25 12:33:29] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1769362405 101 Jan 25 12:33:29 music volumio[20132]: Forking 3 albumart workers Jan 25 12:33:29 music volumio[20059]: 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 25 12:33:29 music volumio[20059]: info: VolumeController:: Volume=86 Mute =false Jan 25 12:33:29 music volumio[20059]: info: CoreStateMachine::pushState Jan 25 12:33:29 music volumio[20059]: info: CorePlayQueue::getTrack 0 Jan 25 12:33:29 music volumio[20059]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 25 12:33:29 music volumio[20059]: info: CoreCommandRouter::volumioPushState Jan 25 12:33:29 music volumio[20059]: info: CoreStateMachine::updateTrackBlock Jan 25 12:33:29 music volumio[20059]: info: CorePlayQueue::getTrackBlock Jan 25 12:33:29 music volumio[20059]: info: CoreCommandRouter::volumioRetrievevolume Jan 25 12:33:29 music volumio[20059]: info: Reloading queue from file Jan 25 12:33:29 music volumio[20059]: info: CoreStateMachine::setRepeat null single undefined Jan 25 12:33:29 music volumio[20059]: info: CoreStateMachine::pushState Jan 25 12:33:29 music volumio[20059]: info: CorePlayQueue::getTrack 0 Jan 25 12:33:29 music volumio[20059]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 25 12:33:29 music volumio[20059]: info: CoreCommandRouter::volumioPushState Jan 25 12:33:29 music volumio[20059]: info: CoreStateMachine::setRandom null Jan 25 12:33:29 music volumio[20059]: info: CoreStateMachine::pushState Jan 25 12:33:29 music volumio[20059]: info: CorePlayQueue::getTrack 0 Jan 25 12:33:29 music volumio[20059]: info: CoreCommandRouter::volumioPushState Jan 25 12:33:29 music volumio[20059]: info: Setting Device type: Raspberry PI Jan 25 12:33:29 music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Jan 25 12:33:29 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 25 12:33:29 music volumio[20059]: info: VolumeController:: Volume=86 Mute =false Jan 25 12:33:29 music volumio[20059]: info: CoreStateMachine::pushState Jan 25 12:33:29 music volumio[20059]: info: CorePlayQueue::getTrack 0 Jan 25 12:33:29 music volumio[20059]: info: CoreCommandRouter::volumioPushState Jan 25 12:33:29 music volumio[20059]: info: Discovery: adding 4a29b7a7-c637-4926-a2bd-fb4e2f55145e Jan 25 12:33:29 music volumio[20059]: info: Discovery: Found device music Jan 25 12:33:29 music volumio[20059]: info: CoreCommandRouter::volumioGetState Jan 25 12:33:29 music volumio[20059]: info: CorePlayQueue::getTrack 0 Jan 25 12:33:29 music volumio[20059]: info: Discovery: this is already registered, 4a29b7a7-c637-4926-a2bd-fb4e2f55145e Jan 25 12:33:29 music volumio[20059]: info: Discovery: Found device music Jan 25 12:33:29 music volumio[20059]: info: CoreCommandRouter::volumioGetState Jan 25 12:33:29 music volumio[20059]: info: CorePlayQueue::getTrack 0 Jan 25 12:33:29 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 25 12:33:29 music go-librespot[20186]: go-librespot daemon starting... Jan 25 12:33:29 music volumio[20059]: info: Completed loading Core Plugins Jan 25 12:33:29 music volumio[20059]: info: Preparing to generate the ALSA configuration file Jan 25 12:33:29 music go-librespot[20187]: time="2026-01-25T12:33:29-05:00" level=info msg="running go-librespot 0.6.2" Jan 25 12:33:29 music go-librespot[20187]: time="2026-01-25T12:33:29-05:00" level=debug msg="app state loaded" Jan 25 12:33:29 music volumio[20059]: info: Asound.conf file unchanged, so no further update is needed Jan 25 12:33:29 music volumio[20059]: info: Output device has changed, restarting MPD Jan 25 12:33:29 music go-librespot[20187]: time="2026-01-25T12:33:29-05:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 25 12:33:29 music volumio[20059]: info: Output device has changed, restarting Shairport Sync Jan 25 12:33:29 music volumio[20059]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:33:29 music volumio[20059]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 12:33:29 music sudo[20196]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 25 12:33:29 music sudo[20196]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 12:33:29 music sudo[20196]: pam_unix(sudo:session): session closed for user root Jan 25 12:33:29 music volumio[20059]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 25 12:33:29 music volumio[20059]: info: ___________ START PLUGINS ___________ Jan 25 12:33:29 music sudo[20198]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 25 12:33:29 music sudo[20198]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 12:33:29 music volumio[20059]: info: ControllerMpd::onStart: Initializing MPD Jan 25 12:33:29 music volumio[20059]: info: Creating MPD Configuration file Jan 25 12:33:29 music systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 25 12:33:29 music volumio[20059]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 25 12:33:29 music volumio[20059]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 25 12:33:29 music volumio[20059]: info: [1769362409927] CoreMusicLibrary::Adding element Media Servers Jan 25 12:33:29 music volumio[20059]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 25 12:33:29 music sudo[20206]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 25 12:33:29 music sudo[20206]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 12:33:29 music sudo[20206]: pam_unix(sudo:session): session closed for user root Jan 25 12:33:30 music volumio[20059]: info: UPNP Browser: Client initialized successfully Jan 25 12:33:30 music sudo[20208]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 25 12:33:30 music sudo[20208]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 12:33:30 music systemd[1]: mpd.service: Deactivated successfully. Jan 25 12:33:30 music systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 25 12:33:30 music systemd[1]: mpd.service: Consumed 4.105s CPU time. Jan 25 12:33:30 music systemd[1]: mpd.socket: Deactivated successfully. Jan 25 12:33:30 music systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 25 12:33:30 music systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 25 12:33:30 music volumio[20059]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:33:30 music volumio[20059]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 12:33:30 music volumio[20059]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 25 12:33:30 music volumio[20059]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:33:30 music volumio[20059]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 12:33:30 music systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 25 12:33:30 music systemd[1]: Starting mpd.service - Music Player Daemon... Jan 25 12:33:30 music volumio[20059]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 25 12:33:30 music volumio[20059]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 25 12:33:30 music volumio[20059]: info: [1769362410192] CoreMusicLibrary::Adding element Last_100 Jan 25 12:33:30 music volumio[20059]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 25 12:33:30 music volumio[20059]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 25 12:33:30 music volumio[20059]: info: [1769362410197] CoreMusicLibrary::Adding element Webradio Jan 25 12:33:30 music systemd[1]: mpd.service: Deactivated successfully. Jan 25 12:33:30 music systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 25 12:33:30 music volumio[20059]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 25 12:33:30 music systemd[1]: mpd.socket: Deactivated successfully. Jan 25 12:33:30 music systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 25 12:33:30 music volumio[20059]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 25 12:33:30 music volumio[20059]: info: Initializing BBC Radios Jan 25 12:33:30 music systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 25 12:33:30 music systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 25 12:33:30 music go-librespot[20187]: time="2026-01-25T12:33:30-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 25 12:33:30 music go-librespot[20187]: time="2026-01-25T12:33:30-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 25 12:33:30 music go-librespot[20187]: time="2026-01-25T12:33:30-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 25 12:33:30 music systemd[1]: Starting mpd.service - Music Player Daemon... Jan 25 12:33:30 music go-librespot[20187]: time="2026-01-25T12:33:30-05:00" level=info msg="zeroconf server listening on port 39011" Jan 25 12:33:30 music volumio[20059]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 25 12:33:30 music volumio[20059]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 12:33:30 music go-librespot[20187]: time="2026-01-25T12:33:30-05:00" level=debug msg="obtained new client token: AADGwotIiIfszYu2d7zkeS5nN/6kWI+TPdTF5XUwUMB9qGh5vAuE419zbMaULVt0io3VOyAdzd8G3/ndMFokzKveaFJYhChc5EDXzagDHizNUiDNOHXyIMcLThsmVOv4EHwKWFZfXuM0hYXkpms6gEQb1Zc9A5tUBbg9FOSJJkNXKif2FBAsdDQrdTjkuteplStWZDfSKWSAQzPX+qhjR11CbTrKHAsvG5R3sk3lLRR+OAYNPjc+Nyk=" Jan 25 12:33:30 music volumio[20059]: info: Creating Spotify config file Jan 25 12:33:30 music volumio[20059]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:33:30 music go-librespot[20187]: time="2026-01-25T12:33:30-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Jan 25 12:33:30 music sudo[20226]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 25 12:33:30 music sudo[20226]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 25 12:33:30 music go-librespot[20187]: time="2026-01-25T12:33:30-05:00" level=debug msg="completed keyexchange" Jan 25 12:33:30 music sudo[20226]: pam_unix(sudo:session): session closed for user root Jan 25 12:33:30 music go-librespot[20187]: time="2026-01-25T12:33:30-05:00" level=debug msg="completed challenge" Jan 25 12:33:30 music go-librespot[20187]: time="2026-01-25T12:33:30-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 25 12:33:30 music volumio[20059]: info: Volumio Calling Home Jan 25 12:33:31 music volumio[20149]: Starting albumart workers Jan 25 12:33:31 music go-librespot[20187]: time="2026-01-25T12:33:31-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 25 12:33:31 music go-librespot[20187]: time="2026-01-25T12:33:31-05:00" level=debug msg="connected to ap-gue1.spotify.com:80" Jan 25 12:33:31 music go-librespot[20187]: time="2026-01-25T12:33:31-05:00" level=debug msg="completed keyexchange" Jan 25 12:33:31 music go-librespot[20187]: time="2026-01-25T12:33:31-05:00" level=debug msg="completed challenge" Jan 25 12:33:31 music volumio[20150]: Starting albumart workers Jan 25 12:33:31 music go-librespot[20187]: time="2026-01-25T12:33:31-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 25 12:33:31 music volumio[20148]: Starting albumart workers Jan 25 12:33:31 music volumio[20059]: info: MPD Permissions set Jan 25 12:33:31 music volumio[20059]: info: MPD Permissions set Jan 25 12:33:31 music volumio[20059]: info: Volumio called home Jan 25 12:33:31 music volumio[20059]: info: Spotify config file written Jan 25 12:33:31 music volumio[20059]: info: CoreCommandRouter::volumioGetState Jan 25 12:33:31 music volumio[20059]: info: CorePlayQueue::getTrack 0 Jan 25 12:33:31 music sudo[20245]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 25 12:33:31 music sudo[20245]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 12:33:31 music systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Jan 25 12:33:31 music systemd[1]: go-librespot-daemon.service: Deactivated successfully. Jan 25 12:33:31 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 25 12:33:31 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 25 12:33:31 music go-librespot[20247]: go-librespot daemon starting... Jan 25 12:33:32 music volumio[20059]: 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 25 12:33:32 music sudo[20245]: pam_unix(sudo:session): session closed for user root Jan 25 12:33:32 music volumio[20059]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:33:32 music volumio[20059]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:33:32 music volumio[20059]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:33:32 music volumio[20059]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:33:32 music volumio[20059]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:33:32 music volumio[20059]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:33:32 music volumio[20059]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:33:32 music volumio[20059]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:33:32 music go-librespot[20248]: time="2026-01-25T12:33:32-05:00" level=info msg="running go-librespot 0.6.2" Jan 25 12:33:32 music go-librespot[20248]: time="2026-01-25T12:33:32-05:00" level=debug msg="app state loaded" Jan 25 12:33:32 music volumio[20059]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 12:33:32 music volumio[20059]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:33:32 music volumio[20059]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:33:32 music volumio[20059]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:33:32 music volumio[20059]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:33:32 music volumio[20059]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:33:32 music volumio[20059]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:33:32 music volumio[20059]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:33:32 music volumio[20059]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:33:32 music volumio[20059]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:33:32 music go-librespot[20248]: time="2026-01-25T12:33:32-05:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 25 12:33:32 music volumio[20059]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 12:33:32 music volumio[20059]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:33:32 music volumio[20059]: info: No need to fix Spotify hosts Jan 25 12:33:32 music go-librespot[20248]: time="2026-01-25T12:33:32-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 25 12:33:32 music go-librespot[20248]: time="2026-01-25T12:33:32-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 25 12:33:32 music go-librespot[20248]: time="2026-01-25T12:33:32-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 25 12:33:32 music go-librespot[20248]: time="2026-01-25T12:33:32-05:00" level=info msg="zeroconf server listening on port 38283" Jan 25 12:33:32 music volumio[20059]: info: Listing playlists Jan 25 12:33:32 music volumio[20059]: info: Listing playlists Jan 25 12:33:32 music volumio[20059]: info: Starting Shairport Sync Jan 25 12:33:32 music go-librespot[20248]: time="2026-01-25T12:33:32-05:00" level=debug msg="obtained new client token: AACJhISFwy3XHslWJsgiS/2lv5RHN6xWNjHw8ZBRQr7sqmiCnHlOM9+befkI/CRqyXofKYI8kpxXrVr3EhG7ORfduS4Ur8zmvQ2x/eOjrXDwMuQouzknt4bw5MoGg65A91u6u/X4zhBGGvFnP94DjypgPfK/cjZeUgU/j1Xu4ED+F1jB8C+5f/mkk+coWd+xvy9G2AwF/2aZBvOT+0fS6humibdC24E8Ul0q8k89t1oioj8Rstuju/0=" Jan 25 12:33:32 music volumio[20059]: info: Starting Shairport Sync Jan 25 12:33:32 music volumio[20059]: info: Starting Shairport Sync Jan 25 12:33:32 music sudo[20280]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 25 12:33:32 music sudo[20280]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 12:33:32 music go-librespot[20248]: time="2026-01-25T12:33:32-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Jan 25 12:33:32 music volumio[20059]: info: An error occurred while refreshing Spotify Token Error: Bad Request Jan 25 12:33:32 music sudo[20283]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 25 12:33:32 music sudo[20283]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 12:33:32 music sudo[20284]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 25 12:33:32 music sudo[20284]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 12:33:32 music systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 25 12:33:32 music systemd[1]: shairport-sync.service: Deactivated successfully. Jan 25 12:33:32 music systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 25 12:33:32 music systemd[1]: shairport-sync.service: Consumed 1.874s CPU time. Jan 25 12:33:32 music go-librespot[20248]: time="2026-01-25T12:33:32-05:00" level=debug msg="completed keyexchange" Jan 25 12:33:32 music go-librespot[20248]: time="2026-01-25T12:33:32-05:00" level=debug msg="completed challenge" Jan 25 12:33:32 music go-librespot[20248]: time="2026-01-25T12:33:32-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 25 12:33:32 music volumio[20059]: info: CoreCommandRouter::volumioGetState Jan 25 12:33:32 music volumio[20059]: info: CorePlayQueue::getTrack 0 Jan 25 12:33:33 music systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 25 12:33:33 music sudo[20280]: pam_unix(sudo:session): session closed for user root Jan 25 12:33:33 music volumio[20059]: info: Shairport-Sync Started Jan 25 12:33:33 music volumio[20059]: Error adding Membership: Error: addMembership EINVAL Jan 25 12:33:33 music systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 25 12:33:33 music systemd[1]: shairport-sync.service: Deactivated successfully. Jan 25 12:33:33 music systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 25 12:33:33 music systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 25 12:33:33 music sudo[20283]: pam_unix(sudo:session): session closed for user root Jan 25 12:33:33 music sudo[20284]: pam_unix(sudo:session): session closed for user root Jan 25 12:33:33 music volumio[20059]: info: Shairport-Sync Started Jan 25 12:33:33 music volumio[20059]: info: Shairport-Sync Started Jan 25 12:33:33 music go-librespot[20248]: time="2026-01-25T12:33:33-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Jan 25 12:33:33 music go-librespot[20248]: time="2026-01-25T12:33:33-05:00" level=debug msg="completed keyexchange" Jan 25 12:33:33 music go-librespot[20248]: time="2026-01-25T12:33:33-05:00" level=debug msg="completed challenge" Jan 25 12:33:33 music go-librespot[20248]: time="2026-01-25T12:33:33-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 25 12:33:34 music go-librespot[20248]: time="2026-01-25T12:33:34-05:00" level=debug msg="connected to ap-gue1.spotify.com:80" Jan 25 12:33:34 music go-librespot[20248]: time="2026-01-25T12:33:34-05:00" level=debug msg="completed keyexchange" Jan 25 12:33:34 music go-librespot[20248]: time="2026-01-25T12:33:34-05:00" level=debug msg="completed challenge" Jan 25 12:33:34 music go-librespot[20248]: time="2026-01-25T12:33:34-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 25 12:33:34 music mpd[20238]: 2026-01-25T12:33:34 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 25 12:33:34 music systemd[1]: Started mpd.service - Music Player Daemon. Jan 25 12:33:34 music sudo[20198]: pam_unix(sudo:session): session closed for user root Jan 25 12:33:34 music sudo[20208]: pam_unix(sudo:session): session closed for user root Jan 25 12:33:34 music volumio[20059]: info: Completed starting Core Plugins Jan 25 12:33:34 music volumio[20059]: info: ------------------------------------------- Jan 25 12:33:34 music volumio[20059]: info: ----- MyVolumio plugins startup ---- Jan 25 12:33:34 music volumio[20059]: info: ------------------------------------------- Jan 25 12:33:34 music volumio[20059]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 25 12:33:34 music volumio[20059]: error: MPD error: The expression evaluated to a falsy value: Jan 25 12:33:34 music volumio[20059]: assert.ok(self.idling) Jan 25 12:33:34 music volumio[20059]: error: The expression evaluated to a falsy value: Jan 25 12:33:34 music volumio[20059]: assert.ok(self.idling) Jan 25 12:33:34 music volumio[20059]: error: updateQueue error: null Jan 25 12:33:34 music volumio[20059]: info: MPD running with PID20238 Jan 25 12:33:34 music volumio[20059]: ,establishing connection Jan 25 12:33:34 music volumio[20059]: error: updateQueue error: null Jan 25 12:33:35 music go-librespot[20248]: time="2026-01-25T12:33:35-05:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 25 12:33:35 music go-librespot[20248]: time="2026-01-25T12:33:35-05:00" level=debug msg="completed keyexchange" Jan 25 12:33:35 music go-librespot[20248]: time="2026-01-25T12:33:35-05:00" level=debug msg="completed challenge" Jan 25 12:33:35 music sudo[20331]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 25 12:33:35 music sudo[20331]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 12:33:35 music sudo[20331]: pam_unix(sudo:session): session closed for user root Jan 25 12:33:35 music sudo[20333]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 25 12:33:35 music sudo[20333]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 12:33:35 music sudo[20333]: pam_unix(sudo:session): session closed for user root Jan 25 12:33:35 music sudo[20336]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 25 12:33:35 music sudo[20336]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 12:33:35 music sudo[20336]: pam_unix(sudo:session): session closed for user root Jan 25 12:33:35 music volumio[20059]: info: Upmpdcli Daemon Started Jan 25 12:33:35 music go-librespot[20248]: time="2026-01-25T12:33:35-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 25 12:33:35 music volumio[20059]: info: go-librespot daemon successfully initialized Jan 25 12:33:36 music go-librespot[20248]: time="2026-01-25T12:33:36-05:00" level=debug msg="connected to ap-gew1.spotify.com:443" Jan 25 12:33:36 music go-librespot[20248]: time="2026-01-25T12:33:36-05:00" level=debug msg="completed keyexchange" Jan 25 12:33:36 music go-librespot[20248]: time="2026-01-25T12:33:36-05:00" level=debug msg="completed challenge" Jan 25 12:33:36 music go-librespot[20248]: time="2026-01-25T12:33:36-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 25 12:33:37 music go-librespot[20248]: time="2026-01-25T12:33:37-05:00" level=debug msg="connected to ap-gew4.spotify.com:80" Jan 25 12:33:37 music go-librespot[20248]: time="2026-01-25T12:33:37-05:00" level=debug msg="completed keyexchange" Jan 25 12:33:37 music go-librespot[20248]: time="2026-01-25T12:33:37-05:00" level=debug msg="completed challenge" Jan 25 12:33:37 music go-librespot[20248]: time="2026-01-25T12:33:37-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 25 12:33:37 music go-librespot[20248]: time="2026-01-25T12:33: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 25 12:33:37 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 25 12:33:37 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 25 12:33:37 music sudo[20340]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Jan 25 12:33:37 music sudo[20340]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 12:33:37 music sudo[20342]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Jan 25 12:33:37 music sudo[20342]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 12:33:37 music systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Jan 25 12:33:37 music systemd[1]: mpd_monitor.service: Deactivated successfully. Jan 25 12:33:37 music systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Jan 25 12:33:37 music systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Jan 25 12:33:37 music sudo[20342]: pam_unix(sudo:session): session closed for user root Jan 25 12:33:37 music sudo[20340]: pam_unix(sudo:session): session closed for user root Jan 25 12:33:37 music volumio[20059]: info: Successfully started MPD Monitor Jan 25 12:33:37 music mpd_monitor.sh[20345]: MPD Monitor Service: Starting MPD Monitor Service Jan 25 12:33:37 music volumio[20059]: info: Successfully started MPD Monitor Jan 25 12:33:38 music volumio[20059]: info: Initializing connection to go-librespot Websocket Jan 25 12:33:38 music volumio[20059]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 25 12:33:39 music volumio[20059]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 25 12:33:39 music volumio[20059]: info: CoreCommandRouter::volumioGetState Jan 25 12:33:39 music volumio[20059]: info: CorePlayQueue::getTrack 0 Jan 25 12:33:40 music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Jan 25 12:33:40 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 25 12:33:40 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 25 12:33:40 music go-librespot[20349]: go-librespot daemon starting... Jan 25 12:33:40 music go-librespot[20350]: time="2026-01-25T12:33:40-05:00" level=info msg="running go-librespot 0.6.2" Jan 25 12:33:40 music go-librespot[20350]: time="2026-01-25T12:33:40-05:00" level=debug msg="app state loaded" Jan 25 12:33:40 music go-librespot[20350]: time="2026-01-25T12:33:40-05:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 25 12:33:40 music go-librespot[20350]: time="2026-01-25T12:33:40-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 25 12:33:40 music go-librespot[20350]: time="2026-01-25T12:33:40-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 25 12:33:40 music go-librespot[20350]: time="2026-01-25T12:33:40-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 25 12:33:40 music go-librespot[20350]: time="2026-01-25T12:33:40-05:00" level=info msg="zeroconf server listening on port 46275" Jan 25 12:33:40 music go-librespot[20350]: time="2026-01-25T12:33:40-05:00" level=debug msg="obtained new client token: AAASbVndi8VXUvNLOwur74UH+d8pkjS8eGimW8u4M/0TYFNwgzQrN7iH0ymHA0cW3Dll8PdFDvNnRfae41KXXg/21MnX07BchW5+o3H/DLb+SVcYNA1xKhwmhXH4LaO+ubzgi3b57fltr5Ztxo6cK+sZGbtjbldiBbGEOXu4HgQabze7M93Kta4L2HabE5SgA0UGoeT/cFDAMSBw+OJg728wZJnjk58MPx/ZL55nfVo10nOiiS/hs5I=" Jan 25 12:33:40 music go-librespot[20350]: time="2026-01-25T12:33:40-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Jan 25 12:33:40 music go-librespot[20350]: time="2026-01-25T12:33:40-05:00" level=debug msg="completed keyexchange" Jan 25 12:33:40 music go-librespot[20350]: time="2026-01-25T12:33:40-05:00" level=debug msg="completed challenge" Jan 25 12:33:41 music go-librespot[20350]: time="2026-01-25T12:33:41-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 25 12:33:41 music go-librespot[20350]: time="2026-01-25T12:33:41-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Jan 25 12:33:41 music volumio[20059]: info: Initializing connection to go-librespot Websocket Jan 25 12:33:41 music volumio[20059]: info: Connection to go-librespot Websocket established Jan 25 12:33:41 music go-librespot[20350]: time="2026-01-25T12:33:41-05:00" level=debug msg="new websocket client" Jan 25 12:33:41 music go-librespot[20350]: time="2026-01-25T12:33:41-05:00" level=debug msg="completed keyexchange" Jan 25 12:33:41 music go-librespot[20350]: time="2026-01-25T12:33:41-05:00" level=debug msg="completed challenge" Jan 25 12:33:41 music go-librespot[20350]: time="2026-01-25T12:33:41-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 25 12:33:42 music go-librespot[20350]: time="2026-01-25T12:33:42-05:00" level=debug msg="connected to ap-gue1.spotify.com:80" Jan 25 12:33:42 music go-librespot[20350]: time="2026-01-25T12:33:42-05:00" level=debug msg="completed keyexchange" Jan 25 12:33:42 music go-librespot[20350]: time="2026-01-25T12:33:42-05:00" level=debug msg="completed challenge" Jan 25 12:33:42 music go-librespot[20350]: time="2026-01-25T12:33:42-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 25 12:33:43 music go-librespot[20350]: time="2026-01-25T12:33:43-05:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 25 12:33:43 music go-librespot[20350]: time="2026-01-25T12:33:43-05:00" level=debug msg="completed keyexchange" Jan 25 12:33:43 music go-librespot[20350]: time="2026-01-25T12:33:43-05:00" level=debug msg="completed challenge" Jan 25 12:33:43 music volumio[20059]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 25 12:33:43 music volumio[20059]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 25 12:33:43 music volumio[20059]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 25 12:33:43 music volumio[20059]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jan 25 12:33:43 music volumio[20059]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 25 12:33:43 music volumio[20059]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 25 12:33:43 music volumio[20059]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 25 12:33:43 music volumio[20059]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 25 12:33:43 music volumio[20059]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 25 12:33:43 music volumio[20059]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 25 12:33:43 music volumio[20059]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jan 25 12:33:43 music volumio[20059]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 25 12:33:43 music volumio[20059]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 25 12:33:43 music volumio[20059]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 25 12:33:43 music volumio[20059]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jan 25 12:33:43 music volumio[20059]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 25 12:33:43 music volumio[20059]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 25 12:33:43 music volumio[20059]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 25 12:33:43 music volumio[20059]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 25 12:33:43 music volumio[20059]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 25 12:33:43 music volumio[20059]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 25 12:33:43 music volumio[20059]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jan 25 12:33:43 music volumio[20059]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 25 12:33:43 music volumio[20059]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jan 25 12:33:43 music volumio[20059]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 25 12:33:43 music volumio[20059]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 25 12:33:43 music volumio[20059]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 25 12:33:43 music volumio[20059]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 25 12:33:43 music volumio[20059]: info: Adding plugin bluetooth to MyMusic Plugins Jan 25 12:33:43 music volumio[20059]: info: Adding plugin multiroom to MyMusic Plugins Jan 25 12:33:43 music volumio[20059]: info: Adding plugin metavolumio to MyMusic Plugins Jan 25 12:33:43 music volumio[20059]: info: Adding plugin cd_controller to MyMusic Plugins Jan 25 12:33:43 music volumio[20059]: info: Adding plugin qobuzconnect to MyMusic Plugins Jan 25 12:33:43 music volumio[20059]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 25 12:33:43 music volumio[20059]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 25 12:33:43 music go-librespot[20350]: time="2026-01-25T12:33:43-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 25 12:33:43 music volumio[20059]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 25 12:33:43 music go-librespot[20350]: time="2026-01-25T12:33:43-05:00" level=debug msg="connected to ap-gew1.spotify.com:443" Jan 25 12:33:43 music go-librespot[20350]: time="2026-01-25T12:33:43-05:00" level=debug msg="completed keyexchange" Jan 25 12:33:43 music go-librespot[20350]: time="2026-01-25T12:33:43-05:00" level=debug msg="completed challenge" Jan 25 12:33:43 music go-librespot[20350]: time="2026-01-25T12:33:43-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 25 12:33:44 music volumio[20059]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 25 12:33:44 music volumio[20059]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 25 12:33:44 music volumio[20059]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 12:33:44 music volumio[20059]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 12:33:44 music volumio[20059]: info: Starting MyVolumio Remote Streaming Endpoints Jan 25 12:33:44 music volumio[20059]: info: MyVolumio login type: Token Jan 25 12:33:44 music volumio[20059]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 25 12:33:44 music volumio[20059]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 25 12:33:44 music go-librespot[20350]: time="2026-01-25T12:33:44-05:00" level=debug msg="connected to ap-gew4.spotify.com:80" Jan 25 12:33:44 music go-librespot[20350]: time="2026-01-25T12:33:44-05:00" level=debug msg="completed keyexchange" Jan 25 12:33:44 music go-librespot[20350]: time="2026-01-25T12:33:44-05:00" level=debug msg="completed challenge" Jan 25 12:33:44 music go-librespot[20350]: time="2026-01-25T12:33:44-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 25 12:33:44 music go-librespot[20350]: time="2026-01-25T12:33:44-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 25 12:33:44 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 25 12:33:44 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 25 12:33:45 music volumio[20059]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 25 12:33:45 music volumio[20059]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 25 12:33:45 music volumio[20059]: info: Streaming services startup Jan 25 12:33:45 music volumio[20059]: info: Starting Streaming Daemon Jan 25 12:33:45 music sudo[20360]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 25 12:33:45 music sudo[20360]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 12:33:45 music volumio[20059]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 25 12:33:45 music sudo[20360]: pam_unix(sudo:session): session closed for user root Jan 25 12:33:45 music volumio[20059]: info: Getting Spotify volume Jan 25 12:33:45 music volumio[20059]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 25 12:33:45 music volumio[20059]: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 25 12:33:45 music volumio[20059]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Jan 25 12:33:45 music volumio[20059]: errno: -111, Jan 25 12:33:45 music volumio[20059]: code: 'ECONNREFUSED', Jan 25 12:33:45 music volumio[20059]: syscall: 'connect', Jan 25 12:33:45 music volumio[20059]: address: '127.0.0.1', Jan 25 12:33:45 music volumio[20059]: port: 9879, Jan 25 12:33:45 music volumio[20059]: response: undefined Jan 25 12:33:45 music volumio[20059]: } Jan 25 12:33:45 music volumio[20059]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 25 12:33:46 music sudo[20394]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-25 12:32' Jan 25 12:33:46 music sudo[20394]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 12:33:46 music sudo[20394]: pam_unix(sudo:session): session closed for user root Jan 25 12:33:46 music volumio-remote-updater[1248]: [2026-01-25 12:33:46] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Jan 25 12:33:46 music systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 25 12:33:46 music volumio-remote-updater[1248]: [2026-01-25 12:33:46] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Jan 25 12:33:46 music systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 25 12:33:46 music systemd[1]: volumio.service: Consumed 26.496s CPU time. Jan 25 12:33:46 music systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 25 12:33:46 music systemd[1]: dynamicswap.service: Deactivated successfully. Jan 25 12:33:46 music systemd[1]: volumio.service: Scheduled restart job, restart counter is at 27814. Jan 25 12:33:46 music systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 25 12:33:46 music systemd[1]: Stopped volumio.service - Volumio Backend Module. Jan 25 12:33:46 music systemd[1]: volumio.service: Consumed 26.496s CPU time. Jan 25 12:33:46 music systemd[1]: Started volumio.service - Volumio Backend Module. Jan 25 12:33:46 music systemd[1]: dynamicswap.service: Deactivated successfully. Jan 25 12:33:48 music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Jan 25 12:33:48 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 25 12:33:48 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 25 12:33:48 music go-librespot[20421]: go-librespot daemon starting... Jan 25 12:33:48 music go-librespot[20422]: time="2026-01-25T12:33:48-05:00" level=info msg="running go-librespot 0.6.2" Jan 25 12:33:48 music go-librespot[20422]: time="2026-01-25T12:33:48-05:00" level=debug msg="app state loaded" Jan 25 12:33:48 music go-librespot[20422]: time="2026-01-25T12:33:48-05:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 25 12:33:48 music go-librespot[20422]: time="2026-01-25T12:33:48-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 25 12:33:48 music go-librespot[20422]: time="2026-01-25T12:33:48-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 25 12:33:48 music go-librespot[20422]: time="2026-01-25T12:33:48-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 25 12:33:48 music go-librespot[20422]: time="2026-01-25T12:33:48-05:00" level=info msg="zeroconf server listening on port 33825" Jan 25 12:33:48 music go-librespot[20422]: time="2026-01-25T12:33:48-05:00" level=debug msg="obtained new client token: AADGeC+JDXgzchjvKX98yE8sV0r4RThBK8dMCyu/RV8WYKAkWh+fj22uwYehxiNCo93vfdnknsA3lUQntc4lPzvSmi3qhtE4LXaqOW4qPN9vIlBFHsAgWJkXf4fTdiPvByUq9JetLkIq531LjMl924SH4WiEQATixU8sIuIV8bFWUABkOK3pp9emRRPSnlmB+mFyh8G/Hf7hDbA6ah9CfwGU0XGz0LhRKd0+dGgAAB/KBd+Ve2t+KTQ=" Jan 25 12:33:48 music go-librespot[20422]: time="2026-01-25T12:33:48-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Jan 25 12:33:48 music go-librespot[20422]: time="2026-01-25T12:33:48-05:00" level=debug msg="completed keyexchange" Jan 25 12:33:48 music go-librespot[20422]: time="2026-01-25T12:33:48-05:00" level=debug msg="completed challenge" Jan 25 12:33:48 music go-librespot[20422]: time="2026-01-25T12:33:48-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 25 12:33:48 music volumio[20406]: info: ------------------------------------------- Jan 25 12:33:48 music volumio[20406]: info: ----- Volumio3 ---- Jan 25 12:33:48 music volumio[20406]: info: ------------------------------------------- Jan 25 12:33:48 music volumio[20406]: info: ----- System startup ---- Jan 25 12:33:48 music volumio[20406]: info: ------------------------------------------- Jan 25 12:33:49 music go-librespot[20422]: time="2026-01-25T12:33:49-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Jan 25 12:33:49 music go-librespot[20422]: time="2026-01-25T12:33:49-05:00" level=debug msg="completed keyexchange" Jan 25 12:33:49 music go-librespot[20422]: time="2026-01-25T12:33:49-05:00" level=debug msg="completed challenge" Jan 25 12:33:49 music go-librespot[20422]: time="2026-01-25T12:33:49-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 25 12:33:49 music volumio[20406]: info: MYVOLUMIO Environment detected Jan 25 12:33:49 music volumio[20406]: info: Plugin folders cleanup Jan 25 12:33:49 music volumio[20406]: info: Scanning into folder /volumio/app/plugins/ Jan 25 12:33:49 music volumio[20406]: info: Scanning category audio_interface Jan 25 12:33:49 music volumio[20406]: info: Scanning category miscellanea Jan 25 12:33:49 music volumio[20406]: info: Scanning category music_service Jan 25 12:33:49 music volumio[20406]: info: Scanning category plugins.json Jan 25 12:33:49 music volumio[20406]: info: Scanning category system_controller Jan 25 12:33:49 music volumio[20406]: info: Scanning category user_interface Jan 25 12:33:49 music volumio[20406]: info: Scanning into folder /data/plugins/ Jan 25 12:33:49 music volumio[20406]: info: Scanning category music_service Jan 25 12:33:49 music volumio[20406]: info: Plugin folders cleanup completed Jan 25 12:33:49 music volumio[20406]: info: ------------------------------------------- Jan 25 12:33:49 music volumio[20406]: info: ----- Core plugins startup ---- Jan 25 12:33:49 music volumio[20406]: info: ------------------------------------------- Jan 25 12:33:49 music volumio[20406]: info: Loading plugins from folder /volumio/app/plugins/ Jan 25 12:33:49 music volumio[20406]: info: Adding plugin upnp to MyMusic Plugins Jan 25 12:33:49 music volumio[20406]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 25 12:33:49 music volumio[20406]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 25 12:33:49 music volumio[20406]: info: Loading plugins from folder /data/plugins/ Jan 25 12:33:49 music volumio[20406]: info: Loading plugin "system"... Jan 25 12:33:49 music volumio[20406]: info: Loading plugin "appearance"... Jan 25 12:33:50 music go-librespot[20422]: time="2026-01-25T12:33:50-05:00" level=debug msg="connected to ap-gue1.spotify.com:80" Jan 25 12:33:50 music go-librespot[20422]: time="2026-01-25T12:33:50-05:00" level=debug msg="completed keyexchange" Jan 25 12:33:50 music go-librespot[20422]: time="2026-01-25T12:33:50-05:00" level=debug msg="completed challenge" Jan 25 12:33:50 music go-librespot[20422]: time="2026-01-25T12:33:50-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 25 12:33:50 music volumio[20406]: info: Loading plugin "network"... Jan 25 12:33:50 music volumio[20406]: info: Refreshing Cached IP Addresses Jan 25 12:33:50 music sudo[20444]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 25 12:33:50 music sudo[20444]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 12:33:50 music sudo[20446]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 25 12:33:50 music sudo[20446]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 12:33:50 music volumio[20406]: info: Loading plugin "services"... Jan 25 12:33:50 music sudo[20444]: pam_unix(sudo:session): session closed for user root Jan 25 12:33:50 music go-librespot[20422]: time="2026-01-25T12:33:50-05:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 25 12:33:50 music volumio[20406]: info: Loading plugin "alsa_controller"... Jan 25 12:33:50 music sudo[20446]: pam_unix(sudo:session): session closed for user root Jan 25 12:33:50 music sudo[20453]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 25 12:33:50 music sudo[20453]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 12:33:51 music volumio[20406]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 25 12:33:51 music volumio[20406]: info: Loading plugin "wizard"... Jan 25 12:33:51 music volumio[20406]: info: Loading plugin "networkfs"... Jan 25 12:33:51 music volumio[20406]: info: Starting Udev Watcher for removable devices Jan 25 12:33:51 music volumio[20406]: info: Ignoring mount for partition: boot Jan 25 12:33:51 music volumio[20406]: info: Ignoring mount for partition: volumio Jan 25 12:33:51 music volumio[20406]: info: Ignoring mount for partition: volumio_data Jan 25 12:33:51 music volumio[20406]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 25 12:33:51 music volumio[20406]: info: Loading plugin "volumio_command_line_client"... Jan 25 12:33:51 music volumio[20406]: info: Loading plugin "upnp"... Jan 25 12:33:51 music volumio[20406]: info: [1769362431135] Starting Upmpd Daemon Jan 25 12:33:51 music volumio[20406]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 25 12:33:51 music volumio[20406]: info: Loading plugin "my_music"... Jan 25 12:33:51 music volumio[20406]: info: Loading plugin "mpd"... Jan 25 12:33:51 music go-librespot[20422]: time="2026-01-25T12:33:51-05:00" level=debug msg="completed keyexchange" Jan 25 12:33:51 music go-librespot[20422]: time="2026-01-25T12:33:51-05:00" level=debug msg="completed challenge" Jan 25 12:33:51 music go-librespot[20422]: time="2026-01-25T12:33:51-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 25 12:33:51 music volumio-remote-updater[1248]: [2026-01-25 12:33:51] [connect] Successful connection Jan 25 12:33:51 music volumio[20406]: info: Loading plugin "upnp_browser"... Jan 25 12:33:51 music sudo[20453]: pam_unix(sudo:session): session closed for user root Jan 25 12:33:52 music go-librespot[20422]: time="2026-01-25T12:33:52-05:00" level=debug msg="connected to ap-gew1.spotify.com:443" Jan 25 12:33:52 music go-librespot[20422]: time="2026-01-25T12:33:52-05:00" level=debug msg="completed keyexchange" Jan 25 12:33:52 music go-librespot[20422]: time="2026-01-25T12:33:52-05:00" level=debug msg="completed challenge" Jan 25 12:33:52 music go-librespot[20422]: time="2026-01-25T12:33:52-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 25 12:33:52 music go-librespot[20422]: time="2026-01-25T12:33:52-05:00" level=debug msg="connected to ap-gew4.spotify.com:80" Jan 25 12:33:53 music volumio[20406]: info: Starting UPNP Browser Jan 25 12:33:53 music volumio[20406]: info: Loading plugin "alarm-clock"... Jan 25 12:33:53 music go-librespot[20422]: time="2026-01-25T12:33:53-05:00" level=debug msg="completed keyexchange" Jan 25 12:33:53 music go-librespot[20422]: time="2026-01-25T12:33:53-05:00" level=debug msg="completed challenge" Jan 25 12:33:53 music go-librespot[20422]: time="2026-01-25T12:33:53-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 25 12:33:53 music go-librespot[20422]: time="2026-01-25T12:33:53-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 25 12:33:53 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 25 12:33:53 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 25 12:33:53 music volumio[20406]: info: Loading plugin "airplay_emulation"... Jan 25 12:33:53 music volumio[20406]: info: Starting Shairport Sync Jan 25 12:33:53 music volumio[20406]: info: Loading plugin "last_100"... Jan 25 12:33:53 music volumio[20406]: info: Loading plugin "webradio"... Jan 25 12:33:53 music volumio[20406]: info: Loading plugin "i2s_dacs"... Jan 25 12:33:53 music volumio[20406]: info: I2S DAC not set, start Auto-detection Jan 25 12:33:53 music volumio[20406]: info: Loading plugin "volumiodiscovery"... Jan 25 12:33:53 music volumio[20406]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 25 12:33:53 music volumio[20406]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 25 12:33:53 music volumio[20406]: *** WARNING *** For more information see Jan 25 12:33:53 music volumio[20406]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 25 12:33:53 music volumio[20406]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 25 12:33:53 music volumio[20406]: *** WARNING *** For more information see Jan 25 12:33:53 music node[20406]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 25 12:33:53 music node[20406]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 25 12:33:53 music node[20406]: *** WARNING *** For more information see Jan 25 12:33:53 music node[20406]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 25 12:33:53 music node[20406]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 25 12:33:53 music node[20406]: *** WARNING *** For more information see Jan 25 12:33:53 music volumio[20406]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 25 12:33:53 music volumio[20406]: info: Discovery: Started advertising with name: music Jan 25 12:33:53 music volumio[20406]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 25 12:33:53 music volumio[20406]: info: Loading plugin "spop"... Jan 25 12:33:54 music volumio[20406]: info: Loading plugin "outputs"... Jan 25 12:33:54 music volumio[20406]: info: Loading plugin "albumart"... Jan 25 12:33:54 music volumio[20406]: info: Plugin example_plugin is not enabled Jan 25 12:33:54 music volumio[20406]: info: Loading plugin "inputs"... Jan 25 12:33:54 music volumio[20406]: info: Loading plugin "updater_comm"... Jan 25 12:33:54 music volumio[20406]: info: Plugin mpdemulation is not enabled Jan 25 12:33:54 music volumio[20406]: info: Loading plugin "rest_api"... Jan 25 12:33:54 music volumio[20406]: info: Loading plugin "websocket"... Jan 25 12:33:54 music volumio[20406]: info: Starting Socket.io Server version 1.7.4 Jan 25 12:33:54 music volumio[20406]: info: Loading i18n strings for locale en Jan 25 12:33:54 music volumio[20406]: Updating browse sources language Jan 25 12:33:54 music volumio[20406]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 25 12:33:54 music volumio[20406]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 25 12:33:54 music volumio[20406]: info: CoreCommandRouter::initPlayerControls Jan 25 12:33:54 music volumio[20406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:33:54 music volumio[20406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:33:54 music volumio[20406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:33:54 music volumio[20406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:33:54 music volumio[20406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:33:54 music volumio[20406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:33:54 music volumio[20406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:33:54 music volumio[20406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:33:54 music volumio[20406]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 25 12:33:54 music volumio[20406]: Express server listening on port 3000 Jan 25 12:33:54 music volumio[20406]: [Metrics] WebUI: 6s 583.57ms Jan 25 12:33:54 music volumio[20406]: info: CoreStateMachine::resetVolumioState Jan 25 12:33:54 music volumio[20406]: info: CoreStateMachine::getcurrentVolume Jan 25 12:33:54 music volumio[20406]: info: CoreCommandRouter::volumioRetrievevolume Jan 25 12:33:54 music volumio[20406]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 12:33:55 music volumio[20406]: info: Volumio Network Manager: Network status updated: 1 Jan 25 12:33:55 music volumio[20479]: Forking 3 albumart workers Jan 25 12:33:55 music volumio[20406]: info: VolumeController:: Volume=86 Mute =false Jan 25 12:33:55 music volumio[20406]: info: CoreStateMachine::pushState Jan 25 12:33:55 music volumio[20406]: info: CorePlayQueue::getTrack 0 Jan 25 12:33:55 music volumio[20406]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 25 12:33:55 music volumio[20406]: info: CoreCommandRouter::volumioPushState Jan 25 12:33:55 music volumio[20406]: info: CoreStateMachine::updateTrackBlock Jan 25 12:33:55 music volumio[20406]: info: CorePlayQueue::getTrackBlock Jan 25 12:33:55 music volumio[20406]: info: CoreCommandRouter::volumioRetrievevolume Jan 25 12:33:55 music volumio[20406]: info: CoreCommandRouter::volumioGetState Jan 25 12:33:55 music volumio[20406]: info: CorePlayQueue::getTrack 0 Jan 25 12:33:55 music volumio-remote-updater[1248]: [2026-01-25 12:33:55] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1769362431 101 Jan 25 12:33:55 music volumio[20406]: 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 25 12:33:55 music volumio[20406]: info: Reloading queue from file Jan 25 12:33:55 music volumio[20406]: info: CoreStateMachine::setRepeat null single undefined Jan 25 12:33:55 music volumio[20406]: info: CoreStateMachine::pushState Jan 25 12:33:55 music volumio[20406]: info: CorePlayQueue::getTrack 0 Jan 25 12:33:55 music volumio[20406]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 25 12:33:55 music volumio[20406]: info: CoreCommandRouter::volumioPushState Jan 25 12:33:55 music volumio[20406]: info: CoreStateMachine::setRandom null Jan 25 12:33:55 music volumio[20406]: info: CoreStateMachine::pushState Jan 25 12:33:55 music volumio[20406]: info: CorePlayQueue::getTrack 0 Jan 25 12:33:55 music volumio[20406]: info: CoreCommandRouter::volumioPushState Jan 25 12:33:55 music volumio[20406]: info: Setting Device type: Raspberry PI Jan 25 12:33:55 music volumio[20406]: info: Listing playlists Jan 25 12:33:55 music volumio[20406]: info: Listing playlists Jan 25 12:33:55 music volumio[20406]: info: VolumeController:: Volume=86 Mute =false Jan 25 12:33:55 music volumio[20406]: info: CoreStateMachine::pushState Jan 25 12:33:55 music volumio[20406]: info: CorePlayQueue::getTrack 0 Jan 25 12:33:55 music volumio[20406]: info: CoreCommandRouter::volumioPushState Jan 25 12:33:55 music volumio[20406]: info: Discovery: adding 4a29b7a7-c637-4926-a2bd-fb4e2f55145e Jan 25 12:33:55 music volumio[20406]: info: Discovery: Found device music Jan 25 12:33:55 music volumio[20406]: info: CoreCommandRouter::volumioGetState Jan 25 12:33:55 music volumio[20406]: info: CorePlayQueue::getTrack 0 Jan 25 12:33:55 music volumio[20406]: info: Discovery: this is already registered, 4a29b7a7-c637-4926-a2bd-fb4e2f55145e Jan 25 12:33:55 music volumio[20406]: info: Discovery: Found device music Jan 25 12:33:55 music volumio[20406]: info: CoreCommandRouter::volumioGetState Jan 25 12:33:55 music volumio[20406]: info: CorePlayQueue::getTrack 0 Jan 25 12:33:55 music volumio[20406]: info: Completed loading Core Plugins Jan 25 12:33:55 music volumio[20406]: info: Preparing to generate the ALSA configuration file Jan 25 12:33:55 music volumio[20406]: info: Asound.conf file unchanged, so no further update is needed Jan 25 12:33:55 music volumio[20406]: info: Output device has changed, restarting MPD Jan 25 12:33:55 music volumio[20406]: info: Output device has changed, restarting Shairport Sync Jan 25 12:33:55 music volumio[20406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:33:55 music volumio[20406]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 12:33:55 music sudo[20535]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 25 12:33:55 music sudo[20535]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 12:33:55 music sudo[20536]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 25 12:33:55 music sudo[20536]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 12:33:55 music sudo[20535]: pam_unix(sudo:session): session closed for user root Jan 25 12:33:55 music volumio[20406]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 25 12:33:55 music volumio[20406]: info: ___________ START PLUGINS ___________ Jan 25 12:33:55 music volumio[20406]: info: ControllerMpd::onStart: Initializing MPD Jan 25 12:33:55 music volumio[20406]: info: Creating MPD Configuration file Jan 25 12:33:55 music systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 25 12:33:55 music volumio[20406]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 25 12:33:55 music volumio[20406]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 25 12:33:55 music sudo[20546]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 25 12:33:55 music sudo[20546]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 12:33:55 music volumio[20406]: info: [1769362435798] CoreMusicLibrary::Adding element Media Servers Jan 25 12:33:55 music volumio[20406]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 25 12:33:55 music sudo[20544]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 25 12:33:55 music systemd[1]: mpd.service: Deactivated successfully. Jan 25 12:33:55 music sudo[20544]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 12:33:55 music systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 25 12:33:55 music volumio[20406]: info: UPNP Browser: Client initialized successfully Jan 25 12:33:55 music systemd[1]: mpd.service: Consumed 4.210s CPU time. Jan 25 12:33:55 music systemd[1]: mpd.socket: Deactivated successfully. Jan 25 12:33:55 music systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 25 12:33:55 music systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 25 12:33:55 music sudo[20544]: pam_unix(sudo:session): session closed for user root Jan 25 12:33:55 music volumio[20406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:33:55 music volumio[20406]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 12:33:55 music systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 25 12:33:55 music systemd[1]: Starting mpd.service - Music Player Daemon... Jan 25 12:33:55 music volumio[20406]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 25 12:33:55 music volumio[20406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:33:55 music volumio[20406]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 12:33:55 music systemd[1]: mpd.service: Deactivated successfully. Jan 25 12:33:55 music systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 25 12:33:55 music systemd[1]: mpd.socket: Deactivated successfully. Jan 25 12:33:55 music systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 25 12:33:55 music systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 25 12:33:55 music systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 25 12:33:55 music volumio[20406]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 25 12:33:55 music volumio[20406]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 25 12:33:55 music volumio[20406]: info: [1769362435967] CoreMusicLibrary::Adding element Last_100 Jan 25 12:33:55 music volumio[20406]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 25 12:33:55 music systemd[1]: Starting mpd.service - Music Player Daemon... Jan 25 12:33:55 music volumio[20406]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 25 12:33:55 music volumio[20406]: info: [1769362435984] CoreMusicLibrary::Adding element Webradio Jan 25 12:33:55 music volumio[20406]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 25 12:33:56 music volumio[20406]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 25 12:33:56 music volumio[20406]: info: Initializing BBC Radios Jan 25 12:33:56 music volumio[20406]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 25 12:33:56 music volumio[20406]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 12:33:56 music volumio[20406]: info: Creating Spotify config file Jan 25 12:33:56 music volumio[20406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:33:56 music sudo[20560]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 25 12:33:56 music sudo[20560]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 25 12:33:56 music sudo[20560]: pam_unix(sudo:session): session closed for user root Jan 25 12:33:56 music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Jan 25 12:33:56 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 25 12:33:56 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 25 12:33:56 music go-librespot[20576]: go-librespot daemon starting... Jan 25 12:33:56 music go-librespot[20577]: time="2026-01-25T12:33:56-05:00" level=info msg="running go-librespot 0.6.2" Jan 25 12:33:56 music volumio[20495]: Starting albumart workers Jan 25 12:33:56 music volumio[20406]: info: Volumio Calling Home Jan 25 12:33:56 music go-librespot[20577]: time="2026-01-25T12:33:56-05:00" level=info msg="zeroconf server listening on port 37351" Jan 25 12:33:57 music volumio[20496]: Starting albumart workers Jan 25 12:33:57 music volumio[20497]: Starting albumart workers Jan 25 12:33:57 music volumio[20406]: info: MPD Permissions set Jan 25 12:33:57 music volumio[20406]: info: MPD Permissions set Jan 25 12:33:57 music volumio[20406]: info: Volumio called home Jan 25 12:33:57 music volumio[20406]: info: Spotify config file written Jan 25 12:33:57 music sudo[20591]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 25 12:33:57 music sudo[20591]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 12:33:57 music volumio[20406]: 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 25 12:33:57 music volumio[20406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:33:57 music volumio[20406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:33:57 music volumio[20406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:33:57 music volumio[20406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:33:57 music volumio[20406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:33:57 music volumio[20406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:33:57 music volumio[20406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:33:57 music volumio[20406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:33:57 music systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Jan 25 12:33:57 music systemd[1]: go-librespot-daemon.service: Deactivated successfully. Jan 25 12:33:57 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 25 12:33:58 music volumio[20406]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 12:33:58 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 25 12:33:58 music volumio[20406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:33:58 music go-librespot[20601]: go-librespot daemon starting... Jan 25 12:33:58 music volumio[20406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:33:58 music volumio[20406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:33:58 music volumio[20406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:33:58 music volumio[20406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:33:58 music sudo[20591]: pam_unix(sudo:session): session closed for user root Jan 25 12:33:58 music volumio[20406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:33:58 music volumio[20406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:33:58 music volumio[20406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:33:58 music volumio[20406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:33:58 music go-librespot[20607]: time="2026-01-25T12:33:58-05:00" level=info msg="running go-librespot 0.6.2" Jan 25 12:33:58 music go-librespot[20607]: time="2026-01-25T12:33:58-05:00" level=debug msg="app state loaded" Jan 25 12:33:58 music volumio[20406]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 12:33:58 music volumio[20406]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:33:58 music volumio[20406]: info: No need to fix Spotify hosts Jan 25 12:33:58 music go-librespot[20607]: time="2026-01-25T12:33:58-05:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 25 12:33:58 music go-librespot[20607]: time="2026-01-25T12:33:58-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 25 12:33:58 music go-librespot[20607]: time="2026-01-25T12:33:58-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 25 12:33:58 music go-librespot[20607]: time="2026-01-25T12:33:58-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 25 12:33:58 music volumio[20406]: info: Starting Shairport Sync Jan 25 12:33:58 music go-librespot[20607]: time="2026-01-25T12:33:58-05:00" level=info msg="zeroconf server listening on port 35081" Jan 25 12:33:58 music volumio[20406]: info: Starting Shairport Sync Jan 25 12:33:58 music volumio[20406]: info: Starting Shairport Sync Jan 25 12:33:58 music sudo[20635]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 25 12:33:58 music sudo[20635]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 12:33:58 music sudo[20637]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 25 12:33:58 music sudo[20637]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 12:33:58 music sudo[20639]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 25 12:33:58 music sudo[20639]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 12:33:58 music volumio[20406]: info: An error occurred while refreshing Spotify Token Error: Bad Request Jan 25 12:33:58 music go-librespot[20607]: time="2026-01-25T12:33:58-05:00" level=debug msg="obtained new client token: AADBaMz4vQB5hj180K47Ia1kIsRoiXXZEdGrLaTrMGKDlOcsfXXrZjIGRqTw9V8ip2GpufQ9C/8T/fLh25llJAcOcVptkR5rUe7yS2Z9jeYgGscf610PCOlG5+TgOAfjLTTlCwr1Qr4vx9N0V47p6L2zzy/vUJmKlaU/JwMBt/3lhDiXUBuz/MthkvEV3E4TtWhsm8+i9sap2diFFvmb90pMY3RDCkCbq0tLFj1S8aastMaVD+K6xcE=" Jan 25 12:33:58 music systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 25 12:33:58 music systemd[1]: shairport-sync.service: Deactivated successfully. Jan 25 12:33:58 music systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 25 12:33:58 music systemd[1]: shairport-sync.service: Consumed 1.887s CPU time. Jan 25 12:33:58 music volumio[20406]: info: CoreCommandRouter::volumioGetState Jan 25 12:33:58 music volumio[20406]: info: CorePlayQueue::getTrack 0 Jan 25 12:33:58 music go-librespot[20607]: time="2026-01-25T12:33:58-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Jan 25 12:33:58 music systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 25 12:33:58 music sudo[20635]: pam_unix(sudo:session): session closed for user root Jan 25 12:33:58 music sudo[20639]: pam_unix(sudo:session): session closed for user root Jan 25 12:33:58 music sudo[20637]: pam_unix(sudo:session): session closed for user root Jan 25 12:33:58 music volumio[20406]: info: Shairport-Sync Started Jan 25 12:33:58 music volumio[20406]: Error adding Membership: Error: addMembership EINVAL Jan 25 12:33:58 music volumio[20406]: info: Shairport-Sync Started Jan 25 12:33:58 music volumio[20406]: info: Shairport-Sync Started Jan 25 12:33:58 music go-librespot[20607]: time="2026-01-25T12:33:58-05:00" level=debug msg="completed keyexchange" Jan 25 12:33:58 music go-librespot[20607]: time="2026-01-25T12:33:58-05:00" level=debug msg="completed challenge" Jan 25 12:33:58 music go-librespot[20607]: time="2026-01-25T12:33:58-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 25 12:33:59 music go-librespot[20607]: time="2026-01-25T12:33:59-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Jan 25 12:33:59 music go-librespot[20607]: time="2026-01-25T12:33:59-05:00" level=debug msg="completed keyexchange" Jan 25 12:33:59 music go-librespot[20607]: time="2026-01-25T12:33:59-05:00" level=debug msg="completed challenge" Jan 25 12:33:59 music go-librespot[20607]: time="2026-01-25T12:33:59-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 25 12:33:59 music volumio[20406]: info: CoreCommandRouter::volumioGetState Jan 25 12:33:59 music volumio[20406]: info: CorePlayQueue::getTrack 0 Jan 25 12:34:00 music go-librespot[20607]: time="2026-01-25T12:34:00-05:00" level=debug msg="connected to ap-gue1.spotify.com:80" Jan 25 12:34:00 music go-librespot[20607]: time="2026-01-25T12:34:00-05:00" level=debug msg="completed keyexchange" Jan 25 12:34:00 music go-librespot[20607]: time="2026-01-25T12:34:00-05:00" level=debug msg="completed challenge" Jan 25 12:34:00 music mpd[20575]: 2026-01-25T12:34:00 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 25 12:34:00 music systemd[1]: Started mpd.service - Music Player Daemon. Jan 25 12:34:00 music sudo[20546]: pam_unix(sudo:session): session closed for user root Jan 25 12:34:00 music sudo[20536]: pam_unix(sudo:session): session closed for user root Jan 25 12:34:00 music go-librespot[20607]: time="2026-01-25T12:34:00-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 25 12:34:00 music volumio[20406]: info: Completed starting Core Plugins Jan 25 12:34:00 music volumio[20406]: info: ------------------------------------------- Jan 25 12:34:00 music volumio[20406]: info: ----- MyVolumio plugins startup ---- Jan 25 12:34:00 music volumio[20406]: info: ------------------------------------------- Jan 25 12:34:00 music volumio[20406]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 25 12:34:00 music volumio[20406]: error: MPD error: The expression evaluated to a falsy value: Jan 25 12:34:00 music volumio[20406]: assert.ok(self.idling) Jan 25 12:34:00 music volumio[20406]: error: The expression evaluated to a falsy value: Jan 25 12:34:00 music volumio[20406]: assert.ok(self.idling) Jan 25 12:34:00 music volumio[20406]: info: MPD running with PID20575 Jan 25 12:34:00 music volumio[20406]: ,establishing connection Jan 25 12:34:00 music volumio[20406]: error: updateQueue error: null Jan 25 12:34:00 music volumio[20406]: error: updateQueue error: null Jan 25 12:34:01 music go-librespot[20607]: time="2026-01-25T12:34:01-05:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 25 12:34:01 music sudo[20680]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 25 12:34:01 music sudo[20680]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 12:34:01 music sudo[20680]: pam_unix(sudo:session): session closed for user root Jan 25 12:34:01 music sudo[20682]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 25 12:34:01 music sudo[20682]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 12:34:01 music sudo[20682]: pam_unix(sudo:session): session closed for user root Jan 25 12:34:01 music sudo[20685]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 25 12:34:01 music sudo[20685]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 12:34:01 music sudo[20685]: pam_unix(sudo:session): session closed for user root Jan 25 12:34:01 music volumio[20406]: info: Upmpdcli Daemon Started Jan 25 12:34:01 music go-librespot[20607]: time="2026-01-25T12:34:01-05:00" level=debug msg="completed keyexchange" Jan 25 12:34:01 music go-librespot[20607]: time="2026-01-25T12:34:01-05:00" level=debug msg="completed challenge" Jan 25 12:34:01 music go-librespot[20607]: time="2026-01-25T12:34:01-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 25 12:34:01 music volumio[20406]: info: go-librespot daemon successfully initialized Jan 25 12:34:02 music go-librespot[20607]: time="2026-01-25T12:34:02-05:00" level=debug msg="connected to ap-gew1.spotify.com:443" Jan 25 12:34:02 music go-librespot[20607]: time="2026-01-25T12:34:02-05:00" level=debug msg="completed keyexchange" Jan 25 12:34:02 music go-librespot[20607]: time="2026-01-25T12:34:02-05:00" level=debug msg="completed challenge" Jan 25 12:34:02 music go-librespot[20607]: time="2026-01-25T12:34:02-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 25 12:34:03 music go-librespot[20607]: time="2026-01-25T12:34:03-05:00" level=debug msg="connected to ap-gew4.spotify.com:80" Jan 25 12:34:03 music go-librespot[20607]: time="2026-01-25T12:34:03-05:00" level=debug msg="completed keyexchange" Jan 25 12:34:03 music go-librespot[20607]: time="2026-01-25T12:34:03-05:00" level=debug msg="completed challenge" Jan 25 12:34:03 music go-librespot[20607]: time="2026-01-25T12:34:03-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 25 12:34:03 music go-librespot[20607]: time="2026-01-25T12:34: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 25 12:34:03 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 25 12:34:03 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 25 12:34:03 music sudo[20689]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Jan 25 12:34:03 music sudo[20689]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 12:34:03 music sudo[20691]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Jan 25 12:34:03 music sudo[20691]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 12:34:03 music systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Jan 25 12:34:03 music systemd[1]: mpd_monitor.service: Deactivated successfully. Jan 25 12:34:03 music systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Jan 25 12:34:03 music systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Jan 25 12:34:03 music sudo[20689]: pam_unix(sudo:session): session closed for user root Jan 25 12:34:03 music mpd_monitor.sh[20694]: MPD Monitor Service: Starting MPD Monitor Service Jan 25 12:34:03 music volumio[20406]: info: Successfully started MPD Monitor Jan 25 12:34:03 music systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Jan 25 12:34:03 music systemd[1]: mpd_monitor.service: Deactivated successfully. Jan 25 12:34:03 music systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Jan 25 12:34:03 music systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Jan 25 12:34:03 music sudo[20691]: pam_unix(sudo:session): session closed for user root Jan 25 12:34:03 music volumio[20406]: info: Successfully started MPD Monitor Jan 25 12:34:03 music mpd_monitor.sh[20697]: MPD Monitor Service: Starting MPD Monitor Service Jan 25 12:34:04 music volumio[20406]: info: Initializing connection to go-librespot Websocket Jan 25 12:34:04 music volumio[20406]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 25 12:34:05 music volumio[20406]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 25 12:34:06 music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Jan 25 12:34:06 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 25 12:34:06 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 25 12:34:06 music go-librespot[20701]: go-librespot daemon starting... Jan 25 12:34:06 music go-librespot[20702]: time="2026-01-25T12:34:06-05:00" level=info msg="running go-librespot 0.6.2" Jan 25 12:34:06 music go-librespot[20702]: time="2026-01-25T12:34:06-05:00" level=debug msg="app state loaded" Jan 25 12:34:06 music go-librespot[20702]: time="2026-01-25T12:34:06-05:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 25 12:34:06 music go-librespot[20702]: time="2026-01-25T12:34: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-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 25 12:34:06 music go-librespot[20702]: time="2026-01-25T12:34:06-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 25 12:34:06 music go-librespot[20702]: time="2026-01-25T12:34:06-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 25 12:34:06 music go-librespot[20702]: time="2026-01-25T12:34:06-05:00" level=info msg="zeroconf server listening on port 40425" Jan 25 12:34:06 music go-librespot[20702]: time="2026-01-25T12:34:06-05:00" level=debug msg="obtained new client token: AADkrxiU0hAWsL4adRYQcwQCK+VWnCRR0dt4CrqAo2u747ofRE8jA7CskwcH7ZeXG3GreI5rcejRqFJ7xm0Sw80I/0q+kVALJ5ooi4MeLgWTxKSJD/RKd5x+Ufk9Wu60COcSKuUdtM5o9belhhMo7jCwGM8PZAcMFmRRYDH0eb6q2PqwzcMyaZsOmvsgljb3eqP016MBMHZGnUjmvcTuyzNpKlzKJzhhWiXbG8vPhkaoe3XYH9u/jd4=" Jan 25 12:34:06 music go-librespot[20702]: time="2026-01-25T12:34:06-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Jan 25 12:34:06 music go-librespot[20702]: time="2026-01-25T12:34:06-05:00" level=debug msg="completed keyexchange" Jan 25 12:34:06 music go-librespot[20702]: time="2026-01-25T12:34:06-05:00" level=debug msg="completed challenge" Jan 25 12:34:07 music go-librespot[20702]: time="2026-01-25T12:34:07-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 25 12:34:07 music volumio[20406]: info: Initializing connection to go-librespot Websocket Jan 25 12:34:07 music go-librespot[20702]: time="2026-01-25T12:34:07-05:00" level=debug msg="new websocket client" Jan 25 12:34:07 music volumio[20406]: info: Connection to go-librespot Websocket established Jan 25 12:34:07 music go-librespot[20702]: time="2026-01-25T12:34:07-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Jan 25 12:34:07 music go-librespot[20702]: time="2026-01-25T12:34:07-05:00" level=debug msg="completed keyexchange" Jan 25 12:34:07 music go-librespot[20702]: time="2026-01-25T12:34:07-05:00" level=debug msg="completed challenge" Jan 25 12:34:07 music go-librespot[20702]: time="2026-01-25T12:34:07-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 25 12:34:08 music go-librespot[20702]: time="2026-01-25T12:34:08-05:00" level=debug msg="connected to ap-gue1.spotify.com:80" Jan 25 12:34:08 music go-librespot[20702]: time="2026-01-25T12:34:08-05:00" level=debug msg="completed keyexchange" Jan 25 12:34:08 music go-librespot[20702]: time="2026-01-25T12:34:08-05:00" level=debug msg="completed challenge" Jan 25 12:34:08 music go-librespot[20702]: time="2026-01-25T12:34:08-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 25 12:34:08 music volumio[20406]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 25 12:34:08 music volumio[20406]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 25 12:34:08 music volumio[20406]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 25 12:34:08 music volumio[20406]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jan 25 12:34:08 music volumio[20406]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 25 12:34:08 music volumio[20406]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 25 12:34:08 music volumio[20406]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 25 12:34:08 music volumio[20406]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 25 12:34:08 music volumio[20406]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 25 12:34:08 music volumio[20406]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 25 12:34:08 music volumio[20406]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jan 25 12:34:08 music volumio[20406]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 25 12:34:08 music volumio[20406]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 25 12:34:08 music volumio[20406]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 25 12:34:08 music volumio[20406]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jan 25 12:34:08 music volumio[20406]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 25 12:34:08 music volumio[20406]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 25 12:34:08 music volumio[20406]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 25 12:34:08 music volumio[20406]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 25 12:34:08 music volumio[20406]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 25 12:34:08 music volumio[20406]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 25 12:34:08 music volumio[20406]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jan 25 12:34:08 music volumio[20406]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 25 12:34:08 music volumio[20406]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jan 25 12:34:08 music volumio[20406]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 25 12:34:08 music volumio[20406]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 25 12:34:08 music volumio[20406]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 25 12:34:08 music volumio[20406]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 25 12:34:08 music volumio[20406]: info: Adding plugin bluetooth to MyMusic Plugins Jan 25 12:34:08 music volumio[20406]: info: Adding plugin multiroom to MyMusic Plugins Jan 25 12:34:08 music volumio[20406]: info: Adding plugin metavolumio to MyMusic Plugins Jan 25 12:34:08 music volumio[20406]: info: Adding plugin cd_controller to MyMusic Plugins Jan 25 12:34:08 music volumio[20406]: info: Adding plugin qobuzconnect to MyMusic Plugins Jan 25 12:34:08 music volumio[20406]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 25 12:34:08 music volumio[20406]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 25 12:34:08 music volumio[20406]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 25 12:34:08 music go-librespot[20702]: time="2026-01-25T12:34:08-05:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 25 12:34:09 music go-librespot[20702]: time="2026-01-25T12:34:09-05:00" level=debug msg="completed keyexchange" Jan 25 12:34:09 music go-librespot[20702]: time="2026-01-25T12:34:09-05:00" level=debug msg="completed challenge" Jan 25 12:34:09 music go-librespot[20702]: time="2026-01-25T12:34:09-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 25 12:34:09 music volumio[20406]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 25 12:34:09 music volumio[20406]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 25 12:34:09 music volumio[20406]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 12:34:09 music volumio[20406]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 12:34:09 music volumio[20406]: info: Starting MyVolumio Remote Streaming Endpoints Jan 25 12:34:09 music volumio[20406]: info: MyVolumio login type: Token Jan 25 12:34:09 music go-librespot[20702]: time="2026-01-25T12:34:09-05:00" level=debug msg="connected to ap-gew1.spotify.com:443" Jan 25 12:34:09 music volumio[20406]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 25 12:34:09 music volumio[20406]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 25 12:34:09 music go-librespot[20702]: time="2026-01-25T12:34:09-05:00" level=debug msg="completed keyexchange" Jan 25 12:34:09 music go-librespot[20702]: time="2026-01-25T12:34:09-05:00" level=debug msg="completed challenge" Jan 25 12:34:09 music go-librespot[20702]: time="2026-01-25T12:34:09-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 25 12:34:10 music go-librespot[20702]: time="2026-01-25T12:34:10-05:00" level=debug msg="connected to ap-gew4.spotify.com:80" Jan 25 12:34:10 music volumio[20406]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 25 12:34:10 music volumio[20406]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 25 12:34:10 music volumio[20406]: info: Streaming services startup Jan 25 12:34:10 music volumio[20406]: info: Starting Streaming Daemon Jan 25 12:34:10 music sudo[20714]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 25 12:34:10 music sudo[20714]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 12:34:10 music volumio[20406]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 25 12:34:10 music sudo[20714]: pam_unix(sudo:session): session closed for user root Jan 25 12:34:10 music go-librespot[20702]: time="2026-01-25T12:34:10-05:00" level=debug msg="completed keyexchange" Jan 25 12:34:10 music go-librespot[20702]: time="2026-01-25T12:34:10-05:00" level=debug msg="completed challenge" Jan 25 12:34:10 music volumio[20406]: info: Getting Spotify volume Jan 25 12:34:10 music volumio[20406]: error: Cannot start Volumio Streaming Daemon Jan 25 12:34:10 music volumio[20406]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 25 12:34:10 music volumio[20406]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 25 12:34:10 music volumio[20406]: info: CoreCommandRouter::volumioGetState Jan 25 12:34:10 music volumio[20406]: info: CorePlayQueue::getTrack 0 Jan 25 12:34:10 music volumio[20406]: 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 25 12:34:10 music volumio[20406]: info: Listing playlists Jan 25 12:34:10 music volumio[20406]: info: Listing playlists Jan 25 12:34:10 music go-librespot[20702]: time="2026-01-25T12:34:10-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 25 12:34:10 music go-librespot[20702]: time="2026-01-25T12:34:10-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 25 12:34:10 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 25 12:34:10 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 25 12:34:10 music volumio[20406]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 25 12:34:10 music volumio[20406]: Error: socket hang up Jan 25 12:34:10 music volumio[20406]: at connResetException (node:internal/errors:720:14) Jan 25 12:34:10 music volumio[20406]: at Socket.socketOnEnd (node:_http_client:519:23) Jan 25 12:34:10 music volumio[20406]: at Socket.emit (node:events:526:35) Jan 25 12:34:10 music volumio[20406]: at endReadableNT (node:internal/streams/readable:1376:12) Jan 25 12:34:10 music volumio[20406]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Jan 25 12:34:10 music volumio[20406]: code: 'ECONNRESET', Jan 25 12:34:10 music volumio[20406]: response: undefined Jan 25 12:34:10 music volumio[20406]: } Jan 25 12:34:10 music volumio[20406]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 25 12:34:11 music sudo[20750]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-25 12:33' Jan 25 12:34:11 music sudo[20750]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 12:34:11 music sudo[20750]: pam_unix(sudo:session): session closed for user root Jan 25 12:34:12 music volumio-remote-updater[1248]: [2026-01-25 12:34:12] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Jan 25 12:34:12 music volumio-remote-updater[1248]: [2026-01-25 12:34:12] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Jan 25 12:34:12 music systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 25 12:34:12 music systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 25 12:34:12 music systemd[1]: volumio.service: Consumed 26.617s CPU time. Jan 25 12:34:12 music systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 25 12:34:12 music systemd[1]: dynamicswap.service: Deactivated successfully. Jan 25 12:34:12 music systemd[1]: volumio.service: Scheduled restart job, restart counter is at 27815. Jan 25 12:34:12 music systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 25 12:34:12 music systemd[1]: Stopped volumio.service - Volumio Backend Module. Jan 25 12:34:12 music systemd[1]: volumio.service: Consumed 26.617s CPU time. Jan 25 12:34:12 music systemd[1]: Started volumio.service - Volumio Backend Module. Jan 25 12:34:12 music systemd[1]: dynamicswap.service: Deactivated successfully. Jan 25 12:34:14 music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Jan 25 12:34:14 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 25 12:34:14 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 25 12:34:14 music go-librespot[20783]: go-librespot daemon starting... Jan 25 12:34:14 music go-librespot[20784]: time="2026-01-25T12:34:14-05:00" level=info msg="running go-librespot 0.6.2" Jan 25 12:34:14 music go-librespot[20784]: time="2026-01-25T12:34:14-05:00" level=debug msg="app state loaded" Jan 25 12:34:14 music go-librespot[20784]: time="2026-01-25T12:34:14-05:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 25 12:34:14 music go-librespot[20784]: time="2026-01-25T12:34:14-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 25 12:34:14 music go-librespot[20784]: time="2026-01-25T12:34:14-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 25 12:34:14 music go-librespot[20784]: time="2026-01-25T12:34:14-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 25 12:34:14 music go-librespot[20784]: time="2026-01-25T12:34:14-05:00" level=info msg="zeroconf server listening on port 34531" Jan 25 12:34:14 music go-librespot[20784]: time="2026-01-25T12:34:14-05:00" level=debug msg="obtained new client token: AADkqp1YIEaQcnQUqt2PuY/KCMevlr7qBCO93/kQLEbALpwfP82y/SePh/YWMN2zn+kDB8JzVPEnw/UwPNPXbpRf2GrWzU9fklEAOPKFYX4z95e1rzp83Irv2Ep650Ie81GWhoScUu2M0tc2/AeneIsinO23tgu8o6OVcoG2khAGt8oYe4va6TO2aRQF99lzv/+554HNHLkexwg/cGPWbMTR4V6rwxfpMf3KNDHR1158PfNTVdhWWfc=" Jan 25 12:34:14 music go-librespot[20784]: time="2026-01-25T12:34:14-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Jan 25 12:34:14 music go-librespot[20784]: time="2026-01-25T12:34:14-05:00" level=debug msg="completed keyexchange" Jan 25 12:34:14 music go-librespot[20784]: time="2026-01-25T12:34:14-05:00" level=debug msg="completed challenge" Jan 25 12:34:14 music volumio[20768]: info: ------------------------------------------- Jan 25 12:34:14 music volumio[20768]: info: ----- Volumio3 ---- Jan 25 12:34:14 music volumio[20768]: info: ------------------------------------------- Jan 25 12:34:14 music volumio[20768]: info: ----- System startup ---- Jan 25 12:34:14 music volumio[20768]: info: ------------------------------------------- Jan 25 12:34:15 music volumio[20768]: info: MYVOLUMIO Environment detected Jan 25 12:34:15 music volumio[20768]: info: Plugin folders cleanup Jan 25 12:34:15 music volumio[20768]: info: Scanning into folder /volumio/app/plugins/ Jan 25 12:34:15 music volumio[20768]: info: Scanning category audio_interface Jan 25 12:34:15 music volumio[20768]: info: Scanning category miscellanea Jan 25 12:34:15 music volumio[20768]: info: Scanning category music_service Jan 25 12:34:15 music volumio[20768]: info: Scanning category plugins.json Jan 25 12:34:15 music volumio[20768]: info: Scanning category system_controller Jan 25 12:34:15 music volumio[20768]: info: Scanning category user_interface Jan 25 12:34:15 music volumio[20768]: info: Scanning into folder /data/plugins/ Jan 25 12:34:15 music volumio[20768]: info: Scanning category music_service Jan 25 12:34:15 music volumio[20768]: info: Plugin folders cleanup completed Jan 25 12:34:15 music volumio[20768]: info: ------------------------------------------- Jan 25 12:34:15 music volumio[20768]: info: ----- Core plugins startup ---- Jan 25 12:34:15 music volumio[20768]: info: ------------------------------------------- Jan 25 12:34:15 music volumio[20768]: info: Loading plugins from folder /volumio/app/plugins/ Jan 25 12:34:15 music volumio[20768]: info: Adding plugin upnp to MyMusic Plugins Jan 25 12:34:15 music volumio[20768]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 25 12:34:15 music volumio[20768]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 25 12:34:15 music volumio[20768]: info: Loading plugins from folder /data/plugins/ Jan 25 12:34:15 music volumio[20768]: info: Loading plugin "system"... Jan 25 12:34:15 music volumio[20768]: info: Loading plugin "appearance"... Jan 25 12:34:16 music go-librespot[20784]: time="2026-01-25T12:34:16-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 25 12:34:16 music go-librespot[20784]: time="2026-01-25T12:34:16-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Jan 25 12:34:16 music go-librespot[20784]: time="2026-01-25T12:34:16-05:00" level=debug msg="completed keyexchange" Jan 25 12:34:16 music go-librespot[20784]: time="2026-01-25T12:34:16-05:00" level=debug msg="completed challenge" Jan 25 12:34:16 music go-librespot[20784]: time="2026-01-25T12:34:16-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 25 12:34:16 music volumio[20768]: info: Loading plugin "network"... Jan 25 12:34:16 music volumio[20768]: info: Refreshing Cached IP Addresses Jan 25 12:34:16 music sudo[20806]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 25 12:34:16 music sudo[20806]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 12:34:16 music sudo[20808]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 25 12:34:16 music sudo[20808]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 12:34:16 music volumio[20768]: info: Loading plugin "services"... Jan 25 12:34:16 music sudo[20806]: pam_unix(sudo:session): session closed for user root Jan 25 12:34:16 music volumio[20768]: info: Loading plugin "alsa_controller"... Jan 25 12:34:16 music sudo[20808]: pam_unix(sudo:session): session closed for user root Jan 25 12:34:16 music sudo[20820]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 25 12:34:16 music sudo[20820]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 12:34:17 music volumio[20768]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 25 12:34:17 music volumio[20768]: info: Loading plugin "wizard"... Jan 25 12:34:17 music volumio[20768]: info: Loading plugin "networkfs"... Jan 25 12:34:17 music volumio[20768]: info: Starting Udev Watcher for removable devices Jan 25 12:34:17 music volumio[20768]: info: Ignoring mount for partition: boot Jan 25 12:34:17 music volumio[20768]: info: Ignoring mount for partition: volumio Jan 25 12:34:17 music volumio[20768]: info: Ignoring mount for partition: volumio_data Jan 25 12:34:17 music volumio[20768]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 25 12:34:17 music volumio[20768]: info: Loading plugin "volumio_command_line_client"... Jan 25 12:34:17 music volumio[20768]: info: Loading plugin "upnp"... Jan 25 12:34:17 music volumio[20768]: info: [1769362457098] Starting Upmpd Daemon Jan 25 12:34:17 music volumio[20768]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 25 12:34:17 music volumio[20768]: info: Loading plugin "my_music"... Jan 25 12:34:17 music volumio[20768]: info: Loading plugin "mpd"... Jan 25 12:34:17 music go-librespot[20784]: time="2026-01-25T12:34:17-05:00" level=debug msg="connected to ap-gue1.spotify.com:80" Jan 25 12:34:17 music go-librespot[20784]: time="2026-01-25T12:34:17-05:00" level=debug msg="completed keyexchange" Jan 25 12:34:17 music go-librespot[20784]: time="2026-01-25T12:34:17-05:00" level=debug msg="completed challenge" Jan 25 12:34:17 music volumio[20768]: info: Loading plugin "upnp_browser"... Jan 25 12:34:17 music go-librespot[20784]: time="2026-01-25T12:34:17-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 25 12:34:17 music sudo[20820]: pam_unix(sudo:session): session closed for user root Jan 25 12:34:17 music volumio-remote-updater[1248]: [2026-01-25 12:34:17] [connect] Successful connection Jan 25 12:34:18 music go-librespot[20784]: time="2026-01-25T12:34:18-05:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Jan 25 12:34:18 music go-librespot[20784]: time="2026-01-25T12:34:18-05:00" level=debug msg="completed keyexchange" Jan 25 12:34:18 music go-librespot[20784]: time="2026-01-25T12:34:18-05:00" level=debug msg="completed challenge" Jan 25 12:34:18 music go-librespot[20784]: time="2026-01-25T12:34:18-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 25 12:34:18 music go-librespot[20784]: time="2026-01-25T12:34:18-05:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 25 12:34:19 music volumio[20768]: info: Starting UPNP Browser Jan 25 12:34:19 music volumio[20768]: info: Loading plugin "alarm-clock"... Jan 25 12:34:19 music go-librespot[20784]: time="2026-01-25T12:34:19-05:00" level=debug msg="completed keyexchange" Jan 25 12:34:19 music go-librespot[20784]: time="2026-01-25T12:34:19-05:00" level=debug msg="completed challenge" Jan 25 12:34:19 music volumio[20768]: info: Loading plugin "airplay_emulation"... Jan 25 12:34:19 music volumio[20768]: info: Starting Shairport Sync Jan 25 12:34:19 music volumio[20768]: info: Loading plugin "last_100"... Jan 25 12:34:19 music volumio[20768]: info: Loading plugin "webradio"... Jan 25 12:34:19 music volumio[20768]: info: Loading plugin "i2s_dacs"... Jan 25 12:34:19 music volumio[20768]: info: I2S DAC not set, start Auto-detection Jan 25 12:34:19 music volumio[20768]: info: Loading plugin "volumiodiscovery"... Jan 25 12:34:19 music go-librespot[20784]: time="2026-01-25T12:34:19-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 25 12:34:19 music volumio[20768]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 25 12:34:19 music volumio[20768]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 25 12:34:19 music volumio[20768]: *** WARNING *** For more information see Jan 25 12:34:19 music volumio[20768]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 25 12:34:19 music volumio[20768]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 25 12:34:19 music volumio[20768]: *** WARNING *** For more information see Jan 25 12:34:19 music node[20768]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 25 12:34:19 music node[20768]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 25 12:34:19 music node[20768]: *** WARNING *** For more information see Jan 25 12:34:19 music node[20768]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 25 12:34:19 music node[20768]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 25 12:34:19 music node[20768]: *** WARNING *** For more information see Jan 25 12:34:19 music volumio[20768]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 25 12:34:19 music volumio[20768]: info: Discovery: Started advertising with name: music Jan 25 12:34:19 music volumio[20768]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 25 12:34:19 music volumio[20768]: info: Loading plugin "spop"... Jan 25 12:34:19 music go-librespot[20784]: time="2026-01-25T12:34:19-05:00" level=warning msg="failed to connect to AP ap-gew1.spotify.com:80, retrying with a different AP" error="dial tcp 104.199.65.9:80: connect: connection refused" Jan 25 12:34:20 music go-librespot[20784]: time="2026-01-25T12:34:20-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Jan 25 12:34:20 music go-librespot[20784]: time="2026-01-25T12:34:20-05:00" level=debug msg="completed keyexchange" Jan 25 12:34:20 music go-librespot[20784]: time="2026-01-25T12:34:20-05:00" level=debug msg="completed challenge" Jan 25 12:34:20 music go-librespot[20784]: time="2026-01-25T12:34:20-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 25 12:34:20 music go-librespot[20784]: time="2026-01-25T12:34: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 25 12:34:20 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 25 12:34:20 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 25 12:34:20 music volumio[20768]: info: Loading plugin "outputs"... Jan 25 12:34:20 music volumio[20768]: info: Loading plugin "albumart"... Jan 25 12:34:20 music volumio[20768]: info: Plugin example_plugin is not enabled Jan 25 12:34:20 music volumio[20768]: info: Loading plugin "inputs"... Jan 25 12:34:20 music volumio[20768]: info: Loading plugin "updater_comm"... Jan 25 12:34:20 music volumio[20768]: info: Plugin mpdemulation is not enabled Jan 25 12:34:20 music volumio[20768]: info: Loading plugin "rest_api"... Jan 25 12:34:20 music volumio[20768]: info: Loading plugin "websocket"... Jan 25 12:34:20 music volumio[20768]: info: Starting Socket.io Server version 1.7.4 Jan 25 12:34:20 music volumio[20768]: info: Loading i18n strings for locale en Jan 25 12:34:20 music volumio[20768]: Updating browse sources language Jan 25 12:34:20 music volumio[20768]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 25 12:34:20 music volumio[20768]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 25 12:34:20 music volumio[20768]: info: CoreCommandRouter::initPlayerControls Jan 25 12:34:20 music volumio[20768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:34:20 music volumio[20768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:34:20 music volumio[20768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:34:20 music volumio[20768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:34:20 music volumio[20768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:34:20 music volumio[20768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:34:20 music volumio[20768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:34:20 music volumio[20768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:34:20 music volumio[20768]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 25 12:34:20 music volumio[20768]: Express server listening on port 3000 Jan 25 12:34:20 music volumio[20768]: [Metrics] WebUI: 6s 603.03ms Jan 25 12:34:20 music volumio[20768]: info: CoreStateMachine::resetVolumioState Jan 25 12:34:20 music volumio[20768]: info: CoreStateMachine::getcurrentVolume Jan 25 12:34:20 music volumio[20768]: info: CoreCommandRouter::volumioRetrievevolume Jan 25 12:34:20 music volumio[20768]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 12:34:21 music volumio[20768]: info: Volumio Network Manager: Network status updated: 1 Jan 25 12:34:21 music volumio-remote-updater[1248]: [2026-01-25 12:34:21] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1769362457 101 Jan 25 12:34:21 music volumio[20841]: Forking 3 albumart workers Jan 25 12:34:21 music volumio[20768]: 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 25 12:34:21 music volumio[20768]: info: VolumeController:: Volume=86 Mute =false Jan 25 12:34:21 music volumio[20768]: info: CoreStateMachine::pushState Jan 25 12:34:21 music volumio[20768]: info: CorePlayQueue::getTrack 0 Jan 25 12:34:21 music volumio[20768]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 25 12:34:21 music volumio[20768]: info: CoreCommandRouter::volumioPushState Jan 25 12:34:21 music volumio[20768]: info: CoreStateMachine::updateTrackBlock Jan 25 12:34:21 music volumio[20768]: info: CorePlayQueue::getTrackBlock Jan 25 12:34:21 music volumio[20768]: info: CoreCommandRouter::volumioRetrievevolume Jan 25 12:34:21 music volumio[20768]: info: Reloading queue from file Jan 25 12:34:21 music volumio[20768]: info: CoreCommandRouter::volumioGetState Jan 25 12:34:21 music volumio[20768]: info: CorePlayQueue::getTrack 0 Jan 25 12:34:21 music volumio[20768]: info: CoreStateMachine::setRepeat null single undefined Jan 25 12:34:21 music volumio[20768]: info: CoreStateMachine::pushState Jan 25 12:34:21 music volumio[20768]: info: CorePlayQueue::getTrack 0 Jan 25 12:34:21 music volumio[20768]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 25 12:34:21 music volumio[20768]: info: CoreCommandRouter::volumioPushState Jan 25 12:34:21 music volumio[20768]: info: CoreStateMachine::setRandom null Jan 25 12:34:21 music volumio[20768]: info: CoreStateMachine::pushState Jan 25 12:34:21 music volumio[20768]: info: CorePlayQueue::getTrack 0 Jan 25 12:34:21 music volumio[20768]: info: CoreCommandRouter::volumioPushState Jan 25 12:34:21 music volumio[20768]: info: Setting Device type: Raspberry PI Jan 25 12:34:21 music volumio[20768]: info: VolumeController:: Volume=86 Mute =false Jan 25 12:34:21 music volumio[20768]: info: CoreStateMachine::pushState Jan 25 12:34:21 music volumio[20768]: info: CorePlayQueue::getTrack 0 Jan 25 12:34:21 music volumio[20768]: info: CoreCommandRouter::volumioPushState Jan 25 12:34:21 music volumio[20768]: info: Completed loading Core Plugins Jan 25 12:34:21 music volumio[20768]: info: Preparing to generate the ALSA configuration file Jan 25 12:34:21 music volumio[20768]: info: Discovery: adding 4a29b7a7-c637-4926-a2bd-fb4e2f55145e Jan 25 12:34:21 music volumio[20768]: info: Discovery: Found device music Jan 25 12:34:21 music volumio[20768]: info: CoreCommandRouter::volumioGetState Jan 25 12:34:21 music volumio[20768]: info: CorePlayQueue::getTrack 0 Jan 25 12:34:21 music volumio[20768]: info: Discovery: this is already registered, 4a29b7a7-c637-4926-a2bd-fb4e2f55145e Jan 25 12:34:21 music volumio[20768]: info: Discovery: Found device music Jan 25 12:34:21 music volumio[20768]: info: CoreCommandRouter::volumioGetState Jan 25 12:34:21 music volumio[20768]: info: CorePlayQueue::getTrack 0 Jan 25 12:34:21 music volumio[20768]: info: Asound.conf file unchanged, so no further update is needed Jan 25 12:34:21 music volumio[20768]: info: Output device has changed, restarting MPD Jan 25 12:34:21 music volumio[20768]: info: Output device has changed, restarting Shairport Sync Jan 25 12:34:21 music volumio[20768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:34:21 music volumio[20768]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 12:34:21 music volumio[20768]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 25 12:34:21 music volumio[20768]: info: ___________ START PLUGINS ___________ Jan 25 12:34:21 music sudo[20895]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 25 12:34:21 music sudo[20895]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 12:34:21 music sudo[20897]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 25 12:34:21 music volumio[20768]: info: ControllerMpd::onStart: Initializing MPD Jan 25 12:34:21 music sudo[20897]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 12:34:21 music volumio[20768]: info: Creating MPD Configuration file Jan 25 12:34:21 music sudo[20895]: pam_unix(sudo:session): session closed for user root Jan 25 12:34:21 music volumio[20768]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 25 12:34:21 music volumio[20768]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 25 12:34:21 music volumio[20768]: info: [1769362461595] CoreMusicLibrary::Adding element Media Servers Jan 25 12:34:21 music volumio[20768]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 25 12:34:21 music volumio[20768]: info: UPNP Browser: Client initialized successfully Jan 25 12:34:21 music sudo[20905]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 25 12:34:21 music systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 25 12:34:21 music sudo[20905]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 12:34:21 music sudo[20907]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 25 12:34:21 music sudo[20905]: pam_unix(sudo:session): session closed for user root Jan 25 12:34:21 music sudo[20907]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 12:34:21 music volumio[20768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:34:21 music volumio[20768]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 12:34:21 music systemd[1]: mpd.service: Deactivated successfully. Jan 25 12:34:21 music systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 25 12:34:21 music systemd[1]: mpd.service: Consumed 4.147s CPU time. Jan 25 12:34:21 music systemd[1]: mpd.socket: Deactivated successfully. Jan 25 12:34:21 music systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 25 12:34:21 music systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 25 12:34:21 music volumio[20768]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 25 12:34:21 music volumio[20768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:34:21 music volumio[20768]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 12:34:21 music volumio[20768]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 25 12:34:21 music volumio[20768]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 25 12:34:21 music volumio[20768]: info: [1769362461813] CoreMusicLibrary::Adding element Last_100 Jan 25 12:34:21 music volumio[20768]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 25 12:34:21 music volumio[20768]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 25 12:34:21 music systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 25 12:34:21 music volumio[20768]: info: [1769362461826] CoreMusicLibrary::Adding element Webradio Jan 25 12:34:21 music volumio[20768]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 25 12:34:21 music volumio[20768]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 25 12:34:21 music systemd[1]: Starting mpd.service - Music Player Daemon... Jan 25 12:34:21 music volumio[20768]: info: Initializing BBC Radios Jan 25 12:34:22 music volumio[20768]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 25 12:34:22 music volumio[20768]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 12:34:22 music volumio[20768]: info: Creating Spotify config file Jan 25 12:34:22 music volumio[20768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:34:22 music sudo[20919]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 25 12:34:22 music sudo[20919]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 25 12:34:22 music sudo[20919]: pam_unix(sudo:session): session closed for user root Jan 25 12:34:22 music volumio[20768]: info: Volumio Calling Home Jan 25 12:34:22 music volumio[20856]: Starting albumart workers Jan 25 12:34:23 music volumio[20858]: Starting albumart workers Jan 25 12:34:23 music volumio[20857]: Starting albumart workers Jan 25 12:34:23 music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Jan 25 12:34:23 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 25 12:34:23 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 25 12:34:23 music go-librespot[20939]: go-librespot daemon starting... Jan 25 12:34:23 music volumio[20768]: info: MPD Permissions set Jan 25 12:34:23 music volumio[20768]: info: MPD Permissions set Jan 25 12:34:23 music volumio[20768]: info: Volumio called home Jan 25 12:34:23 music go-librespot[20940]: time="2026-01-25T12:34:23-05:00" level=info msg="running go-librespot 0.6.2" Jan 25 12:34:23 music go-librespot[20940]: time="2026-01-25T12:34:23-05:00" level=debug msg="app state loaded" Jan 25 12:34:23 music volumio[20768]: info: Spotify config file written Jan 25 12:34:23 music go-librespot[20940]: time="2026-01-25T12:34:23-05:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 25 12:34:23 music sudo[20949]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 25 12:34:23 music sudo[20949]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 12:34:23 music systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Jan 25 12:34:23 music systemd[1]: go-librespot-daemon.service: Deactivated successfully. Jan 25 12:34:23 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 25 12:34:23 music volumio[20768]: 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 25 12:34:23 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 25 12:34:23 music sudo[20949]: pam_unix(sudo:session): session closed for user root Jan 25 12:34:23 music go-librespot[20953]: go-librespot daemon starting... Jan 25 12:34:23 music volumio[20768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:34:23 music volumio[20768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:34:23 music volumio[20768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:34:23 music volumio[20768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:34:23 music volumio[20768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:34:23 music volumio[20768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:34:23 music volumio[20768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:34:23 music volumio[20768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:34:23 music volumio[20768]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 12:34:23 music volumio[20768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:34:23 music go-librespot[20954]: time="2026-01-25T12:34:23-05:00" level=info msg="running go-librespot 0.6.2" Jan 25 12:34:23 music go-librespot[20954]: time="2026-01-25T12:34:23-05:00" level=debug msg="app state loaded" Jan 25 12:34:23 music volumio[20768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:34:23 music volumio[20768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:34:23 music volumio[20768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:34:23 music volumio[20768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:34:23 music volumio[20768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:34:23 music volumio[20768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:34:23 music volumio[20768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:34:23 music volumio[20768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:34:23 music go-librespot[20954]: time="2026-01-25T12:34:23-05:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 25 12:34:23 music volumio[20768]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 25 12:34:23 music volumio[20768]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 25 12:34:23 music volumio[20768]: info: No need to fix Spotify hosts Jan 25 12:34:24 music go-librespot[20954]: time="2026-01-25T12:34:24-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 25 12:34:24 music go-librespot[20954]: time="2026-01-25T12:34:24-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 25 12:34:24 music go-librespot[20954]: time="2026-01-25T12:34:24-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 25 12:34:24 music go-librespot[20954]: time="2026-01-25T12:34:24-05:00" level=info msg="zeroconf server listening on port 35213" Jan 25 12:34:24 music volumio[20768]: info: An error occurred while refreshing Spotify Token Error: Bad Request Jan 25 12:34:24 music volumio[20768]: info: Starting Shairport Sync Jan 25 12:34:24 music go-librespot[20954]: time="2026-01-25T12:34:24-05:00" level=debug msg="obtained new client token: AACchG1iBvwXwMD9ZE5dlKQ2JQuayZjPNvU0Qvyymq0+Do2gHitZQTHmnhe0C/pqP+R15hZr8dQ/Tmr67/ezGACqo/pBnTte1hSxyEUgNHgcvzOpMhcQJWhIEKxh3K94nOf2Q3HrsI5OHNa/ggNJ5ZmDQLbJjxVhml6eqdGgmpOcDGz8E9RNxIZtUrQ6TZ1DckomQFu3U4ETPGXr3eUpjo8Pqqk4pRK/7Xn4+iUczxvCa+i7WY+V4KA=" Jan 25 12:34:24 music volumio[20768]: info: Starting Shairport Sync Jan 25 12:34:24 music volumio[20768]: info: Starting Shairport Sync Jan 25 12:34:24 music sudo[20986]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 25 12:34:24 music go-librespot[20954]: time="2026-01-25T12:34:24-05:00" level=warning msg="failed to connect to AP ap-gue1.spotify.com:4070, retrying with a different AP" error="dial tcp 34.158.255.62:4070: connect: connection refused" Jan 25 12:34:24 music sudo[20986]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 12:34:24 music sudo[20991]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 25 12:34:24 music sudo[20991]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 12:34:24 music sudo[20988]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 25 12:34:24 music sudo[20988]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 12:34:24 music go-librespot[20954]: time="2026-01-25T12:34:24-05:00" level=debug msg="connected to ap-gue1.spotify.com:443" Jan 25 12:34:24 music volumio[20768]: info: CoreCommandRouter::volumioGetState Jan 25 12:34:24 music volumio[20768]: info: CorePlayQueue::getTrack 0 Jan 25 12:34:24 music go-librespot[20954]: time="2026-01-25T12:34:24-05:00" level=debug msg="completed keyexchange" Jan 25 12:34:24 music go-librespot[20954]: time="2026-01-25T12:34:24-05:00" level=debug msg="completed challenge" Jan 25 12:34:24 music systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 25 12:34:24 music systemd[1]: shairport-sync.service: Deactivated successfully. Jan 25 12:34:24 music systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 25 12:34:24 music systemd[1]: shairport-sync.service: Consumed 1.882s CPU time. Jan 25 12:34:24 music go-librespot[20954]: time="2026-01-25T12:34:24-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 25 12:34:24 music systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 25 12:34:24 music sudo[20991]: pam_unix(sudo:session): session closed for user root Jan 25 12:34:24 music sudo[20986]: pam_unix(sudo:session): session closed for user root Jan 25 12:34:24 music sudo[20988]: pam_unix(sudo:session): session closed for user root Jan 25 12:34:24 music volumio[20768]: info: Shairport-Sync Started Jan 25 12:34:24 music volumio[20768]: Error adding Membership: Error: addMembership EINVAL Jan 25 12:34:24 music volumio[20768]: info: Shairport-Sync Started Jan 25 12:34:24 music volumio[20768]: info: Shairport-Sync Started Jan 25 12:34:25 music go-librespot[20954]: time="2026-01-25T12:34:25-05:00" level=debug msg="connected to ap-gue1.spotify.com:80" Jan 25 12:34:26 music mpd[20935]: 2026-01-25T12:34:26 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 25 12:34:26 music systemd[1]: Started mpd.service - Music Player Daemon. Jan 25 12:34:26 music sudo[20897]: pam_unix(sudo:session): session closed for user root Jan 25 12:34:26 music sudo[20907]: pam_unix(sudo:session): session closed for user root Jan 25 12:34:26 music volumio[20768]: info: Completed starting Core Plugins Jan 25 12:34:26 music volumio[20768]: info: ------------------------------------------- Jan 25 12:34:26 music volumio[20768]: info: ----- MyVolumio plugins startup ---- Jan 25 12:34:26 music volumio[20768]: info: ------------------------------------------- Jan 25 12:34:26 music volumio[20768]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 25 12:34:26 music volumio[20768]: error: MPD error: The expression evaluated to a falsy value: Jan 25 12:34:26 music volumio[20768]: assert.ok(self.idling) Jan 25 12:34:26 music volumio[20768]: error: The expression evaluated to a falsy value: Jan 25 12:34:26 music volumio[20768]: assert.ok(self.idling) Jan 25 12:34:26 music volumio[20768]: info: MPD running with PID20935 Jan 25 12:34:26 music volumio[20768]: ,establishing connection Jan 25 12:34:26 music volumio[20768]: error: updateQueue error: null Jan 25 12:34:26 music volumio[20768]: error: updateQueue error: null Jan 25 12:34:26 music go-librespot[20954]: time="2026-01-25T12:34:26-05:00" level=debug msg="completed keyexchange" Jan 25 12:34:26 music go-librespot[20954]: time="2026-01-25T12:34:26-05:00" level=debug msg="completed challenge" Jan 25 12:34:26 music go-librespot[20954]: time="2026-01-25T12:34:26-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 25 12:34:27 music sudo[21038]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 25 12:34:27 music sudo[21038]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 12:34:27 music sudo[21038]: pam_unix(sudo:session): session closed for user root Jan 25 12:34:27 music sudo[21040]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 25 12:34:27 music sudo[21040]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 12:34:27 music sudo[21043]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 25 12:34:27 music sudo[21043]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 12:34:27 music sudo[21040]: pam_unix(sudo:session): session closed for user root Jan 25 12:34:27 music sudo[21043]: pam_unix(sudo:session): session closed for user root Jan 25 12:34:27 music volumio[20768]: info: Upmpdcli Daemon Started Jan 25 12:34:27 music volumio[20768]: info: go-librespot daemon successfully initialized Jan 25 12:34:27 music go-librespot[20954]: time="2026-01-25T12:34:27-05:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 25 12:34:27 music go-librespot[20954]: time="2026-01-25T12:34:27-05:00" level=debug msg="completed keyexchange" Jan 25 12:34:27 music go-librespot[20954]: time="2026-01-25T12:34:27-05:00" level=debug msg="completed challenge" Jan 25 12:34:27 music go-librespot[20954]: time="2026-01-25T12:34:27-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 25 12:34:28 music go-librespot[20954]: time="2026-01-25T12:34:28-05:00" level=debug msg="connected to ap-gew1.spotify.com:443" Jan 25 12:34:28 music go-librespot[20954]: time="2026-01-25T12:34:28-05:00" level=debug msg="completed keyexchange" Jan 25 12:34:28 music go-librespot[20954]: time="2026-01-25T12:34:28-05:00" level=debug msg="completed challenge" Jan 25 12:34:28 music go-librespot[20954]: time="2026-01-25T12:34:28-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 25 12:34:29 music sudo[21047]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Jan 25 12:34:29 music sudo[21047]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 12:34:29 music sudo[21049]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd_monitor.service Jan 25 12:34:29 music sudo[21049]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 12:34:29 music systemd[1]: Stopping mpd_monitor.service - MPD Monitor Service... Jan 25 12:34:29 music systemd[1]: mpd_monitor.service: Deactivated successfully. Jan 25 12:34:29 music systemd[1]: Stopped mpd_monitor.service - MPD Monitor Service. Jan 25 12:34:29 music systemd[1]: Started mpd_monitor.service - MPD Monitor Service. Jan 25 12:34:29 music sudo[21049]: pam_unix(sudo:session): session closed for user root Jan 25 12:34:29 music sudo[21047]: pam_unix(sudo:session): session closed for user root Jan 25 12:34:29 music mpd_monitor.sh[21052]: MPD Monitor Service: Starting MPD Monitor Service Jan 25 12:34:29 music volumio[20768]: info: Successfully started MPD Monitor Jan 25 12:34:29 music volumio[20768]: info: Successfully started MPD Monitor Jan 25 12:34:29 music go-librespot[20954]: time="2026-01-25T12:34:29-05:00" level=debug msg="connected to ap-gew4.spotify.com:80" Jan 25 12:34:29 music go-librespot[20954]: time="2026-01-25T12:34:29-05:00" level=debug msg="completed keyexchange" Jan 25 12:34:29 music go-librespot[20954]: time="2026-01-25T12:34:29-05:00" level=debug msg="completed challenge" Jan 25 12:34:29 music go-librespot[20954]: time="2026-01-25T12:34:29-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 25 12:34:29 music volumio[20768]: info: CoreCommandRouter::volumioGetState Jan 25 12:34:29 music volumio[20768]: info: CorePlayQueue::getTrack 0 Jan 25 12:34:29 music volumio[20768]: info: Listing playlists Jan 25 12:34:29 music volumio[20768]: info: Listing playlists Jan 25 12:34:30 music go-librespot[20954]: time="2026-01-25T12:34:30-05:00" level=debug msg="connected to ap-gue1.spotify.com:4070" Jan 25 12:34:30 music volumio[20768]: info: Initializing connection to go-librespot Websocket Jan 25 12:34:30 music go-librespot[20954]: time="2026-01-25T12:34:30-05:00" level=debug msg="new websocket client" Jan 25 12:34:30 music volumio[20768]: info: Connection to go-librespot Websocket established Jan 25 12:34:30 music go-librespot[20954]: time="2026-01-25T12:34:30-05:00" level=debug msg="completed keyexchange" Jan 25 12:34:30 music go-librespot[20954]: time="2026-01-25T12:34:30-05:00" level=debug msg="completed challenge" Jan 25 12:34:30 music go-librespot[20954]: time="2026-01-25T12:34:30-05:00" level=warning msg="failed connecting to accesspoint, retrying" error="failed authenticating: accesspoint login failed: BadCredentials " Jan 25 12:34:30 music go-librespot[20954]: time="2026-01-25T12:34: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 25 12:34:30 music systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 25 12:34:30 music systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 25 12:34:30 music volumio[20768]: info: Connection to go-librespot Websocket closed Jan 25 12:34:31 music volumio[20768]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 25 12:34:33 music volumio[20768]: info: Getting Spotify volume Jan 25 12:34:33 music volumio[20768]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 25 12:34:33 music volumio[20768]: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 25 12:34:33 music volumio[20768]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Jan 25 12:34:33 music volumio[20768]: errno: -111, Jan 25 12:34:33 music volumio[20768]: code: 'ECONNREFUSED', Jan 25 12:34:33 music volumio[20768]: syscall: 'connect', Jan 25 12:34:33 music volumio[20768]: address: '127.0.0.1', Jan 25 12:34:33 music volumio[20768]: port: 9879, Jan 25 12:34:33 music volumio[20768]: response: undefined Jan 25 12:34:33 music volumio[20768]: } Jan 25 12:34:33 music volumio[20768]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 25 12:34:33 music systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Jan 25 12:34:33 music systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 25 12:34:33 music systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 25 12:34:33 music go-librespot[21069]: go-librespot daemon starting... Jan 25 12:34:33 music go-librespot[21070]: time="2026-01-25T12:34:33-05:00" level=info msg="running go-librespot 0.6.2" Jan 25 12:34:33 music go-librespot[21070]: time="2026-01-25T12:34:33-05:00" level=debug msg="app state loaded" Jan 25 12:34:33 music go-librespot[21070]: time="2026-01-25T12:34:33-05:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 25 12:34:34 music sudo[21081]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-25 12:33' Jan 25 12:34:34 music go-librespot[21070]: time="2026-01-25T12:34:34-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 25 12:34:34 music go-librespot[21070]: time="2026-01-25T12:34:34-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 25 12:34:34 music go-librespot[21070]: time="2026-01-25T12:34:34-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 25 12:34:34 music sudo[21081]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 25 12:34:34 music go-librespot[21070]: time="2026-01-25T12:34:34-05:00" level=info msg="zeroconf server listening on port 34983" Jan 25 12:34:34 music go-librespot[21070]: time="2026-01-25T12:34:34-05:00" level=debug msg="obtained new client token: AAD7b3X646ZJU3OaOIx08Kzc5MTPdZUt7B8jI0TeKmdWEXgVdBVZYudSxYfi0AjilFwCr0fLn5Xd9jgF8/qSKtyo42BeNjgdoDBkX1kJpk3yoC6C4FVx7oUrQsMxTz9PK9gVV+oTZEmS2zOQ9BkvahsbMTYUmIegRuiPnUmBfl/EqeKTX/rT60yaQD88Lfq67buYyxGAytq3ca9czscm51T9FlnDWjI8WSQaC++Fm4c6KaGgat0oANE=" Jan 25 12:34:34 music go-librespot[21070]: time="2026-01-25T12:34:34-05:00" level=warning msg="failed to connect to AP ap-gue1.spotify.com:4070, retrying with a different AP" error="dial tcp 34.158.255.62:4070: connect: connection refused" 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"