Feb 18 18:54:00 volumio go-librespot[3656]: time="2026-02-18T18:54:00+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 18:54:00 volumio go-librespot[3656]: time="2026-02-18T18:54:00+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 18:54:00 volumio go-librespot[3656]: time="2026-02-18T18:54:00+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 18:54:00 volumio go-librespot[3656]: time="2026-02-18T18:54:00+07:00" level=info msg="zeroconf server listening on port 41645" Feb 18 18:54:00 volumio go-librespot[3656]: time="2026-02-18T18:54:00+07:00" level=debug msg="obtained new client token: AADE8mJl69/h8bh5VxjHNOQcQLMGS68jgNqv5o1MNIZebpKoPJOzfEj9aOVDGRgxvrh+gbCyPyizV38NMN4xDqUNmPNu5SGzGDMAXSlH5pQ8lRald+v8E3hhZdSuR+XTu9taw+6pZRzxWrD8ogwrtqQrVrW/FOF6qSw2HJ5DEyJxI+G4iJf5nayHVQ6oSrPpfwMCSvRihacOAdnCK1TpKPWBHtCqVmo/UyGixE6dOKinD08IO1Ec/BrJDw==" Feb 18 18:54:00 volumio go-librespot[3656]: time="2026-02-18T18:54:00+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Feb 18 18:54:00 volumio go-librespot[3656]: time="2026-02-18T18:54:00+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 18 18:54:00 volumio go-librespot[3656]: time="2026-02-18T18:54:00+07:00" level=debug msg="completed keyexchange" Feb 18 18:54:00 volumio go-librespot[3656]: time="2026-02-18T18:54:00+07:00" level=debug msg="completed challenge" Feb 18 18:54:01 volumio go-librespot[3656]: time="2026-02-18T18:54:01+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 18:54:01 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 18:54:01 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 18:54:01 volumio volumio[3620]: info: Loading plugin "network"... Feb 18 18:54:01 volumio volumio[3620]: info: Refreshing Cached IP Addresses Feb 18 18:54:01 volumio sudo[3665]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 18 18:54:01 volumio sudo[3665]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 18:54:01 volumio sudo[3667]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 18 18:54:01 volumio volumio[3620]: info: Loading plugin "services"... Feb 18 18:54:01 volumio sudo[3667]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 18:54:01 volumio volumio[3620]: info: Loading plugin "alsa_controller"... Feb 18 18:54:01 volumio sudo[3665]: pam_unix(sudo:session): session closed for user root Feb 18 18:54:01 volumio sudo[3667]: pam_unix(sudo:session): session closed for user root Feb 18 18:54:01 volumio sudo[3675]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 18 18:54:01 volumio sudo[3675]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 18:54:01 volumio volumio[3620]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 18 18:54:01 volumio volumio[3620]: info: Loading plugin "wizard"... Feb 18 18:54:01 volumio volumio[3620]: info: Loading plugin "networkfs"... Feb 18 18:54:01 volumio volumio[3620]: info: Starting Udev Watcher for removable devices Feb 18 18:54:01 volumio volumio[3620]: info: Ignoring mount for partition: boot Feb 18 18:54:01 volumio volumio[3620]: info: Ignoring mount for partition: volumio Feb 18 18:54:01 volumio volumio[3620]: info: Ignoring mount for partition: volumio_data Feb 18 18:54:01 volumio volumio[3620]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 18 18:54:01 volumio volumio[3620]: info: Loading plugin "volumio_command_line_client"... Feb 18 18:54:01 volumio volumio[3620]: info: Loading plugin "upnp"... Feb 18 18:54:01 volumio volumio[3620]: info: [1771415641942] Starting Upmpd Daemon Feb 18 18:54:01 volumio volumio[3620]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 18 18:54:01 volumio volumio[3620]: info: Loading plugin "my_music"... Feb 18 18:54:01 volumio volumio[3620]: info: Loading plugin "mpd"... Feb 18 18:54:02 volumio volumio[3620]: info: Loading plugin "upnp_browser"... Feb 18 18:54:04 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Feb 18 18:54:04 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 18:54:04 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 18:54:04 volumio go-librespot[3699]: go-librespot daemon starting... Feb 18 18:54:04 volumio go-librespot[3700]: time="2026-02-18T18:54:04+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 18:54:04 volumio go-librespot[3700]: time="2026-02-18T18:54:04+07:00" level=debug msg="app state loaded" Feb 18 18:54:04 volumio go-librespot[3700]: time="2026-02-18T18:54:04+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 18:54:04 volumio sudo[3675]: pam_unix(sudo:session): session closed for user root Feb 18 18:54:04 volumio go-librespot[3700]: time="2026-02-18T18:54:04+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 18:54:04 volumio go-librespot[3700]: time="2026-02-18T18:54:04+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 18:54:04 volumio go-librespot[3700]: time="2026-02-18T18:54:04+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 18:54:04 volumio go-librespot[3700]: time="2026-02-18T18:54:04+07:00" level=info msg="zeroconf server listening on port 32879" Feb 18 18:54:05 volumio go-librespot[3700]: time="2026-02-18T18:54:05+07:00" level=debug msg="obtained new client token: AADNt6xonAmj0BaYSWqEZDMLJMFwGzIazzGkjjopjW8oYM+/YRdLDyYXAGxj0s5d8qvmFa0Bhio8fobE3g7wuS0/nfzX6znbIILJm4E+0RBlJ6QTb3xu573Nszld8U8pc16W+9PdUi/fgdh5t9by6BYooPM0C5w8gr9gXPxwKNAgcGFAAluY3GZWLz8oVncnUeRSS2ZyEVX2Wgx3XcmVVRXhwS+QdzP1Z9cIydBiSS916m0pR81WzYo=" Feb 18 18:54:05 volumio go-librespot[3700]: time="2026-02-18T18:54:05+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 18:54:05 volumio go-librespot[3700]: time="2026-02-18T18:54:05+07:00" level=debug msg="completed keyexchange" Feb 18 18:54:05 volumio go-librespot[3700]: time="2026-02-18T18:54:05+07:00" level=debug msg="completed challenge" Feb 18 18:54:05 volumio volumio[3620]: info: Starting UPNP Browser Feb 18 18:54:05 volumio volumio[3620]: info: Loading plugin "alarm-clock"... Feb 18 18:54:05 volumio go-librespot[3700]: time="2026-02-18T18:54:05+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 18:54:05 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 18:54:05 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 18:54:05 volumio volumio[3620]: info: Loading plugin "airplay_emulation"... Feb 18 18:54:05 volumio volumio[3620]: info: Starting Shairport Sync Feb 18 18:54:05 volumio volumio[3620]: info: Loading plugin "last_100"... Feb 18 18:54:05 volumio volumio[3620]: info: Loading plugin "webradio"... Feb 18 18:54:06 volumio volumio[3620]: info: Loading plugin "i2s_dacs"... Feb 18 18:54:06 volumio volumio[3620]: info: Loading plugin "volumiodiscovery"... Feb 18 18:54:06 volumio volumio[3620]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 18 18:54:06 volumio volumio[3620]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 18:54:06 volumio volumio[3620]: *** WARNING *** For more information see Feb 18 18:54:06 volumio volumio[3620]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 18 18:54:06 volumio volumio[3620]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 18:54:06 volumio volumio[3620]: *** WARNING *** For more information see Feb 18 18:54:06 volumio node[3620]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 18 18:54:06 volumio node[3620]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 18:54:06 volumio node[3620]: *** WARNING *** For more information see Feb 18 18:54:06 volumio node[3620]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 18 18:54:06 volumio node[3620]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 18:54:06 volumio node[3620]: *** WARNING *** For more information see Feb 18 18:54:06 volumio volumio[3620]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 18 18:54:06 volumio volumio[3620]: info: Discovery: Started advertising with name: Volumio Feb 18 18:54:06 volumio volumio[3620]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 18 18:54:06 volumio volumio[3620]: info: Loading plugin "spop"... Feb 18 18:54:08 volumio volumio[3620]: info: Loading plugin "ytcr"... Feb 18 18:54:08 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Feb 18 18:54:08 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 18:54:08 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 18:54:08 volumio go-librespot[3711]: go-librespot daemon starting... Feb 18 18:54:08 volumio go-librespot[3712]: time="2026-02-18T18:54:08+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 18:54:08 volumio go-librespot[3712]: time="2026-02-18T18:54:08+07:00" level=debug msg="app state loaded" Feb 18 18:54:08 volumio go-librespot[3712]: time="2026-02-18T18:54:08+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 18:54:09 volumio go-librespot[3712]: time="2026-02-18T18:54:09+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 18:54:09 volumio go-librespot[3712]: time="2026-02-18T18:54:09+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 18:54:09 volumio go-librespot[3712]: time="2026-02-18T18:54:09+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 18:54:09 volumio go-librespot[3712]: time="2026-02-18T18:54:09+07:00" level=info msg="zeroconf server listening on port 34311" Feb 18 18:54:09 volumio go-librespot[3712]: time="2026-02-18T18:54:09+07:00" level=debug msg="obtained new client token: AACNPWLyfRSmgBBbrWeP88xlzxxjvsxk0r5CKG4jEeWe7WF4HJpCEkZFt7nfAO20QDolnYqpAXmKzd1mmZgLGmZUmQ/PRkWxSBk6LXr8zOcTtDe7af/c0wTizds7FD9SAaq0L7YSFPSsFjD63TQjp+aGWj3TDI5nXmi0UFdYU36+6GkU8zFZUsYbGjDQ5BBzS8lzWMlVLcwShiAEgpv2SEp71Z2ZGUOQZNfPucR0cSUHY6txMI5nnPgkqA==" Feb 18 18:54:09 volumio go-librespot[3712]: time="2026-02-18T18:54:09+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 18:54:09 volumio go-librespot[3712]: time="2026-02-18T18:54:09+07:00" level=debug msg="completed keyexchange" Feb 18 18:54:09 volumio go-librespot[3712]: time="2026-02-18T18:54:09+07:00" level=debug msg="completed challenge" Feb 18 18:54:09 volumio go-librespot[3712]: time="2026-02-18T18:54:09+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 18:54:09 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 18:54:09 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 18:54:10 volumio volumio[3620]: info: Loading plugin "ytmusic"... Feb 18 18:54:11 volumio volumio-remote-updater[25144]: [2026-02-18 18:54:11] [connect] Successful connection Feb 18 18:54:11 volumio volumio[3620]: info: Loading plugin "outputs"... Feb 18 18:54:11 volumio volumio[3620]: info: Loading plugin "albumart"... Feb 18 18:54:11 volumio volumio[3620]: info: Plugin example_plugin is not enabled Feb 18 18:54:11 volumio volumio[3620]: info: Loading plugin "inputs"... Feb 18 18:54:11 volumio volumio[3620]: info: Loading plugin "updater_comm"... Feb 18 18:54:12 volumio volumio[3620]: info: Plugin mpdemulation is not enabled Feb 18 18:54:12 volumio volumio[3620]: info: Loading plugin "rest_api"... Feb 18 18:54:12 volumio volumio[3620]: info: Loading plugin "websocket"... Feb 18 18:54:12 volumio volumio[3620]: info: Starting Socket.io Server version 1.7.4 Feb 18 18:54:12 volumio volumio[3620]: info: Loading plugin "RoonBridge"... Feb 18 18:54:12 volumio volumio[3620]: info: Applying required configuration parameters for plugin RoonBridge Feb 18 18:54:12 volumio volumio[3620]: info: Loading i18n strings for locale en Feb 18 18:54:12 volumio volumio[3620]: Updating browse sources language Feb 18 18:54:12 volumio volumio[3620]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 18:54:13 volumio volumio[3620]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 18 18:54:13 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Feb 18 18:54:13 volumio volumio[3620]: info: CoreCommandRouter::initPlayerControls Feb 18 18:54:13 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 18:54:13 volumio volumio[3620]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 18:54:13 volumio volumio[3620]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 18:54:13 volumio volumio[3620]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 18:54:13 volumio volumio[3620]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 18:54:13 volumio volumio[3620]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 18:54:13 volumio volumio[3620]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 18:54:13 volumio volumio[3620]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 18:54:13 volumio volumio[3620]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 18:54:13 volumio volumio[3620]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 18 18:54:13 volumio volumio[3734]: Forking 3 albumart workers Feb 18 18:54:13 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 18:54:13 volumio volumio[3620]: Express server listening on port 3000 Feb 18 18:54:13 volumio volumio[3620]: [Metrics] WebUI: 16s 32.90ms Feb 18 18:54:13 volumio go-librespot[3744]: go-librespot daemon starting... Feb 18 18:54:13 volumio volumio[3620]: info: CoreStateMachine::resetVolumioState Feb 18 18:54:13 volumio go-librespot[3745]: time="2026-02-18T18:54:13+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 18:54:13 volumio go-librespot[3745]: time="2026-02-18T18:54:13+07:00" level=debug msg="app state loaded" Feb 18 18:54:13 volumio volumio[3620]: info: CoreStateMachine::getcurrentVolume Feb 18 18:54:13 volumio volumio[3620]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 18:54:13 volumio go-librespot[3745]: time="2026-02-18T18:54:13+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 18:54:13 volumio sudo[3784]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 18 18:54:13 volumio sudo[3784]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 18:54:13 volumio sudo[3784]: pam_unix(sudo:session): session closed for user root Feb 18 18:54:13 volumio sudo[3787]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 18 18:54:13 volumio sudo[3787]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 18:54:13 volumio sudo[3787]: pam_unix(sudo:session): session closed for user root Feb 18 18:54:13 volumio volumio[3620]: info: Volumio Network Manager: Network status updated: 1 Feb 18 18:54:13 volumio go-librespot[3745]: time="2026-02-18T18:54:13+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 18:54:13 volumio go-librespot[3745]: time="2026-02-18T18:54:13+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 18:54:13 volumio go-librespot[3745]: time="2026-02-18T18:54:13+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 18:54:13 volumio go-librespot[3745]: time="2026-02-18T18:54:13+07:00" level=info msg="zeroconf server listening on port 39285" Feb 18 18:54:13 volumio volumio-remote-updater[25144]: [2026-02-18 18:54:13] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1771415651 101 Feb 18 18:54:13 volumio volumio[3620]: 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 Feb 18 18:54:13 volumio volumio[3620]: info: VolumeController:: Volume=100 Mute =false Feb 18 18:54:13 volumio volumio[3620]: info: CoreStateMachine::pushState Feb 18 18:54:13 volumio volumio[3620]: info: CorePlayQueue::getTrack 0 Feb 18 18:54:13 volumio volumio[3620]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 18 18:54:13 volumio volumio[3620]: info: CoreCommandRouter::volumioPushState Feb 18 18:54:14 volumio volumio[3620]: info: CoreStateMachine::updateTrackBlock Feb 18 18:54:14 volumio volumio[3620]: info: CorePlayQueue::getTrackBlock Feb 18 18:54:14 volumio volumio[3620]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 18:54:14 volumio volumio[3620]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 18:54:14 volumio volumio[3620]: info: Reloading queue from file Feb 18 18:54:14 volumio volumio[3620]: info: Setting Device type: Raspberry PI Feb 18 18:54:14 volumio volumio[3620]: info: CoreStateMachine::setRepeat null single undefined Feb 18 18:54:14 volumio volumio[3620]: info: CoreStateMachine::pushState Feb 18 18:54:14 volumio volumio[3620]: info: CorePlayQueue::getTrack 0 Feb 18 18:54:14 volumio volumio[3620]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 18 18:54:14 volumio volumio[3620]: info: CoreCommandRouter::volumioPushState Feb 18 18:54:14 volumio volumio[3620]: info: CoreStateMachine::setRandom null Feb 18 18:54:14 volumio volumio[3620]: info: CoreStateMachine::pushState Feb 18 18:54:14 volumio volumio[3620]: info: CorePlayQueue::getTrack 0 Feb 18 18:54:14 volumio volumio[3620]: info: CoreCommandRouter::volumioPushState Feb 18 18:54:14 volumio volumio[3620]: info: Completed loading Core Plugins Feb 18 18:54:14 volumio volumio[3620]: info: Preparing to generate the ALSA configuration file Feb 18 18:54:14 volumio go-librespot[3745]: time="2026-02-18T18:54:14+07:00" level=debug msg="obtained new client token: AACT0reSZMb3rpJXV24tJz4mutdjNSeOF3Hp905xWw5Mnf9ab5Ehn2BPFs1pt5joB47KIRZHKzKNsF59phCJpM3klOMrLVtbIP2jSNgYLb8AW8Ag6ULvPoUOvaXjrHy/1Ic+kzg6X4Tzo3nvEpH7HIbqiv0Q93xMNZRY7s+xy7Otr+WAEuYi1r5enovYBJDJO2KvHACthrrfSgldbNktNCf0vHKX0jzUC52yJfp58YXdf7WW3CYhL/U=" Feb 18 18:54:14 volumio go-librespot[3745]: time="2026-02-18T18:54:14+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 18:54:14 volumio volumio[3620]: info: VolumeController:: Volume=100 Mute =false Feb 18 18:54:14 volumio volumio[3620]: info: CoreStateMachine::pushState Feb 18 18:54:14 volumio volumio[3620]: info: CorePlayQueue::getTrack 0 Feb 18 18:54:14 volumio volumio[3620]: info: CoreCommandRouter::volumioPushState Feb 18 18:54:14 volumio volumio[3620]: info: Asound.conf file unchanged, so no further update is needed Feb 18 18:54:14 volumio volumio[3620]: info: Output device has changed, restarting MPD Feb 18 18:54:14 volumio sudo[3805]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 18 18:54:14 volumio sudo[3805]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 18:54:14 volumio go-librespot[3745]: time="2026-02-18T18:54:14+07:00" level=debug msg="completed keyexchange" Feb 18 18:54:14 volumio volumio[3620]: info: Output device has changed, restarting Shairport Sync Feb 18 18:54:14 volumio go-librespot[3745]: time="2026-02-18T18:54:14+07:00" level=debug msg="completed challenge" Feb 18 18:54:14 volumio volumio[3620]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 18:54:14 volumio volumio[3620]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 18:54:14 volumio sudo[3808]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 18 18:54:14 volumio sudo[3808]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 18:54:14 volumio go-librespot[3745]: time="2026-02-18T18:54:14+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 18:54:14 volumio volumio[3620]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 18 18:54:14 volumio sudo[3808]: pam_unix(sudo:session): session closed for user root Feb 18 18:54:14 volumio sudo[3805]: pam_unix(sudo:session): session closed for user root Feb 18 18:54:14 volumio volumio[3620]: info: ___________ START PLUGINS ___________ Feb 18 18:54:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 18:54:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 18:54:14 volumio sudo[3810]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 18 18:54:14 volumio sudo[3810]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 18:54:14 volumio volumio[3620]: info: ControllerMpd::onStart: Initializing MPD Feb 18 18:54:14 volumio volumio[3620]: info: Creating MPD Configuration file Feb 18 18:54:14 volumio volumio[3620]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 18 18:54:14 volumio volumio[3620]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 18:54:14 volumio volumio[3620]: info: [1771415654722] CoreMusicLibrary::Adding element Media Servers Feb 18 18:54:14 volumio volumio[3620]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 18:54:14 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 18 18:54:14 volumio sudo[3818]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 18 18:54:14 volumio volumio[3620]: info: UPNP Browser: Client initialized successfully Feb 18 18:54:14 volumio sudo[3818]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 18:54:14 volumio sudo[3818]: pam_unix(sudo:session): session closed for user root Feb 18 18:54:14 volumio sudo[3820]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 18 18:54:14 volumio sudo[3820]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 18:54:14 volumio volumio[3620]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 18:54:14 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 18 18:54:14 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 18 18:54:14 volumio systemd[1]: mpd.service: Consumed 7.053s CPU time. Feb 18 18:54:14 volumio volumio[3620]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 18:54:14 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 18 18:54:14 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 18 18:54:14 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 18 18:54:14 volumio volumio[3620]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 18 18:54:14 volumio volumio[3620]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 18:54:14 volumio volumio[3620]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 18:54:15 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 18 18:54:15 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 18 18:54:15 volumio volumio[3620]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 18 18:54:15 volumio volumio[3620]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 18:54:15 volumio volumio[3620]: info: [1771415655112] CoreMusicLibrary::Adding element Last_100 Feb 18 18:54:15 volumio volumio[3620]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 18:54:15 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 18 18:54:15 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 18 18:54:15 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 18 18:54:15 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 18 18:54:15 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 18 18:54:15 volumio volumio[3620]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 18:54:15 volumio volumio[3620]: info: [1771415655132] CoreMusicLibrary::Adding element Webradio Feb 18 18:54:15 volumio volumio[3620]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 18:54:15 volumio volumio[3620]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 18 18:54:15 volumio volumio[3620]: info: Initializing BBC Radios Feb 18 18:54:15 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 18 18:54:15 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 18 18:54:15 volumio volumio[3620]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 18 18:54:15 volumio volumio[3620]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 18:54:15 volumio volumio[3620]: info: Creating Spotify config file Feb 18 18:54:15 volumio volumio[3620]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 18:54:15 volumio sudo[3839]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 18 18:54:15 volumio sudo[3839]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 18 18:54:15 volumio sudo[3839]: pam_unix(sudo:session): session closed for user root Feb 18 18:54:16 volumio volumio[3620]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 18:54:16 volumio volumio[3620]: info: [1771415656524] CoreMusicLibrary::Adding element YouTube Music Feb 18 18:54:16 volumio volumio[3620]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 18:54:16 volumio volumio[3620]: Cannot find translation for source YouTube Music Feb 18 18:54:16 volumio volumio[3746]: Starting albumart workers Feb 18 18:54:16 volumio volumio[3620]: info: Volumio Calling Home Feb 18 18:54:16 volumio volumio[3757]: Starting albumart workers Feb 18 18:54:16 volumio sudo[3851]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 18 18:54:16 volumio sudo[3851]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 18:54:16 volumio sudo[3851]: pam_unix(sudo:session): session closed for user root Feb 18 18:54:16 volumio volumio[3756]: Starting albumart workers Feb 18 18:54:17 volumio volumio[3620]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 18 18:54:17 volumio volumio[3620]: info: Discovery: Found device Volumio Feb 18 18:54:17 volumio volumio[3620]: info: CoreCommandRouter::volumioGetState Feb 18 18:54:17 volumio volumio[3620]: info: CorePlayQueue::getTrack 0 Feb 18 18:54:17 volumio volumio[3620]: info: MPD Permissions set Feb 18 18:54:17 volumio volumio[3620]: info: MPD Permissions set Feb 18 18:54:17 volumio volumio[3620]: info: Upmpdcli Daemon Started Feb 18 18:54:17 volumio volumio[3620]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 18 18:54:17 volumio volumio[3620]: info: Discovery: Found device Volumio Feb 18 18:54:17 volumio volumio[3620]: info: CoreCommandRouter::volumioGetState Feb 18 18:54:17 volumio volumio[3620]: info: CorePlayQueue::getTrack 0 Feb 18 18:54:17 volumio volumio[3620]: info: Volumio called home Feb 18 18:54:17 volumio volumio[3620]: info: Spotify config file written Feb 18 18:54:17 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Feb 18 18:54:17 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 18:54:17 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 18:54:17 volumio go-librespot[3858]: go-librespot daemon starting... Feb 18 18:54:17 volumio sudo[3857]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 18 18:54:17 volumio sudo[3857]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 18:54:17 volumio go-librespot[3859]: time="2026-02-18T18:54:17+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 18:54:17 volumio go-librespot[3859]: time="2026-02-18T18:54:17+07:00" level=debug msg="app state loaded" Feb 18 18:54:17 volumio go-librespot[3859]: time="2026-02-18T18:54:17+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 18:54:18 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 18 18:54:18 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 18 18:54:18 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 18:54:18 volumio volumio[3620]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Feb 18 18:54:18 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 18:54:18 volumio go-librespot[3866]: go-librespot daemon starting... Feb 18 18:54:18 volumio volumio[3620]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 18:54:18 volumio volumio[3620]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 18:54:18 volumio volumio[3620]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 18:54:18 volumio volumio[3620]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 18:54:18 volumio volumio[3620]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 18:54:18 volumio volumio[3620]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 18:54:18 volumio volumio[3620]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 18:54:18 volumio volumio[3620]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 18:54:18 volumio sudo[3857]: pam_unix(sudo:session): session closed for user root Feb 18 18:54:18 volumio go-librespot[3867]: time="2026-02-18T18:54:18+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 18:54:18 volumio go-librespot[3867]: time="2026-02-18T18:54:18+07:00" level=debug msg="app state loaded" Feb 18 18:54:18 volumio go-librespot[3867]: time="2026-02-18T18:54:18+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 18:54:18 volumio volumio[3620]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 18:54:18 volumio volumio[3620]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 18:54:18 volumio volumio[3620]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 18:54:18 volumio volumio[3620]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 18:54:18 volumio volumio[3620]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 18:54:18 volumio volumio[3620]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 18:54:18 volumio volumio[3620]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 18:54:18 volumio volumio[3620]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 18:54:18 volumio volumio[3620]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 18:54:18 volumio volumio[3620]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 18:54:18 volumio volumio[3620]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 18:54:18 volumio volumio[3620]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 18:54:18 volumio volumio[3620]: info: No need to fix Spotify hosts Feb 18 18:54:18 volumio go-librespot[3867]: time="2026-02-18T18:54:18+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 18:54:18 volumio go-librespot[3867]: time="2026-02-18T18:54:18+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 18:54:18 volumio go-librespot[3867]: time="2026-02-18T18:54:18+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 18:54:18 volumio go-librespot[3867]: time="2026-02-18T18:54:18+07:00" level=info msg="zeroconf server listening on port 41833" Feb 18 18:54:19 volumio go-librespot[3867]: time="2026-02-18T18:54:19+07:00" level=debug msg="obtained new client token: AABiwQgwit214dqz8VuEEipna4xzzbhBw4x29UoBE10J3YWr/c5a29WaNb/c/43wVf6v8BizTXYGokJhpHydPHOKZojIx/++wILhABwI78Dx0gL/C24s7Pyf5r36gkFniasxEgcheC7j1XVOpHooct+5nmJPgxo5JNgAPvvreBaMviS9cGjigvLvdFEGxBVRqoCFqAvZCOndJ9HZ87SgJCCe3aGp5AhQyZofY/t3kdjgEc1rppf/qm0=" Feb 18 18:54:19 volumio go-librespot[3867]: time="2026-02-18T18:54:19+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 18:54:19 volumio go-librespot[3867]: time="2026-02-18T18:54:19+07:00" level=debug msg="completed keyexchange" Feb 18 18:54:19 volumio go-librespot[3867]: time="2026-02-18T18:54:19+07:00" level=debug msg="completed challenge" Feb 18 18:54:19 volumio volumio[3620]: info: Starting Shairport Sync Feb 18 18:54:19 volumio volumio[3620]: info: Starting Shairport Sync Feb 18 18:54:19 volumio go-librespot[3867]: time="2026-02-18T18:54:19+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 18:54:19 volumio volumio[3620]: info: Starting Shairport Sync Feb 18 18:54:19 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 18:54:19 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 18:54:19 volumio sudo[3904]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 18:54:19 volumio sudo[3904]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 18:54:19 volumio volumio[3620]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 18 18:54:19 volumio volumio[3620]: SPOTIFY: BQCNhJhKbrQOtd4eLYpwbrV9aCp77iQl0x3fpck6RJA0FS7KPDoJkC_JNvQIbrmIhYQrQTUmhmfVUJhin7OAqyWsH94B___3jkcw3S7EtQhhvByqFrHmFM5NPJeAgRryh7GCaqv1_CZB6WlFgx3oo7WTHVhMvqDlBg7-Y9uwiF_9NdUPRsGljt7sk5rz12Qxw0iqT8xrTQHASKHLg5oQsPXMZvoFKSsgNCH1We1HVNJ7XC4L68J1GjC4TyrB_e8UxpI9atngdsyhI61VywQV4mlxMPK3R7_Us5vYNsTiAa2dfcDRnvK78-rQ Feb 18 18:54:19 volumio volumio[3620]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 18 18:54:19 volumio volumio[3620]: info: New Spotify access token = BQCNhJhKbrQOtd4eLYpwbrV9aCp77iQl0x3fpck6RJA0FS7KPDoJkC_JNvQIbrmIhYQrQTUmhmfVUJhin7OAqyWsH94B___3jkcw3S7EtQhhvByqFrHmFM5NPJeAgRryh7GCaqv1_CZB6WlFgx3oo7WTHVhMvqDlBg7-Y9uwiF_9NdUPRsGljt7sk5rz12Qxw0iqT8xrTQHASKHLg5oQsPXMZvoFKSsgNCH1We1HVNJ7XC4L68J1GjC4TyrB_e8UxpI9atngdsyhI61VywQV4mlxMPK3R7_Us5vYNsTiAa2dfcDRnvK78-rQ Feb 18 18:54:19 volumio volumio[3620]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 18 18:54:19 volumio sudo[3906]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 18:54:19 volumio sudo[3906]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 18:54:19 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 18 18:54:19 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 18 18:54:19 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 18:54:19 volumio systemd[1]: shairport-sync.service: Consumed 2.372s CPU time. Feb 18 18:54:19 volumio sudo[3908]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 18:54:19 volumio sudo[3908]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 18:54:19 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 18:54:19 volumio sudo[3904]: pam_unix(sudo:session): session closed for user root Feb 18 18:54:19 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 18 18:54:19 volumio volumio[3620]: info: Shairport-Sync Started Feb 18 18:54:19 volumio volumio[3620]: Error adding Membership: Error: addMembership EINVAL Feb 18 18:54:19 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 18 18:54:19 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 18:54:20 volumio volumio[3620]: info: CoreCommandRouter::volumioGetState Feb 18 18:54:20 volumio volumio[3620]: info: CorePlayQueue::getTrack 0 Feb 18 18:54:20 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 18:54:20 volumio sudo[3908]: pam_unix(sudo:session): session closed for user root Feb 18 18:54:20 volumio sudo[3906]: pam_unix(sudo:session): session closed for user root Feb 18 18:54:20 volumio volumio[3620]: info: Shairport-Sync Started Feb 18 18:54:20 volumio volumio[3620]: info: Shairport-Sync Started Feb 18 18:54:20 volumio volumio[3620]: SPOTIFY: User informations: {"country":"PK","display_name":"215mmgea6kss3jxeqsqdquvji","email":"linh.ngotran@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/215mmgea6kss3jxeqsqdquvji"},"followers":{"href":null,"total":1},"href":"https://api.spotify.com/v1/users/215mmgea6kss3jxeqsqdquvji","id":"215mmgea6kss3jxeqsqdquvji","images":[],"product":"premium","type":"user","uri":"spotify:user:215mmgea6kss3jxeqsqdquvji"} Feb 18 18:54:20 volumio volumio[3620]: info: Spotify Successfully logged in Feb 18 18:54:20 volumio volumio[3620]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 18:54:20 volumio volumio[3620]: info: [1771415660412] CoreMusicLibrary::Adding element Spotify Feb 18 18:54:20 volumio volumio[3620]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 18:54:20 volumio volumio[3620]: Cannot find translation for source YouTube Music Feb 18 18:54:20 volumio volumio[3620]: Cannot find translation for source Spotify Feb 18 18:54:20 volumio volumio[3620]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 18 18:54:20 volumio volumio[3620]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 18:54:21 volumio volumio[3620]: info: VolumeController:: Volume=100 Mute =false Feb 18 18:54:21 volumio volumio[3620]: info: CoreCommandRouter::volumioGetState Feb 18 18:54:21 volumio volumio[3620]: info: CorePlayQueue::getTrack 0 Feb 18 18:54:21 volumio volumio[3620]: info: CoreStateMachine::pushState Feb 18 18:54:21 volumio volumio[3620]: info: CorePlayQueue::getTrack 0 Feb 18 18:54:21 volumio volumio[3620]: info: CoreCommandRouter::volumioPushState Feb 18 18:54:22 volumio volumio[3620]: info: go-librespot daemon successfully initialized Feb 18 18:54:22 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 18 18:54:22 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 18:54:22 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 18:54:22 volumio go-librespot[3958]: go-librespot daemon starting... Feb 18 18:54:22 volumio go-librespot[3959]: time="2026-02-18T18:54:22+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 18:54:22 volumio go-librespot[3959]: time="2026-02-18T18:54:22+07:00" level=debug msg="app state loaded" Feb 18 18:54:22 volumio go-librespot[3959]: time="2026-02-18T18:54:22+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 18:54:22 volumio mpd[3849]: 2026-02-18T18:54:22 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 18 18:54:22 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 18 18:54:22 volumio sudo[3810]: pam_unix(sudo:session): session closed for user root Feb 18 18:54:22 volumio sudo[3820]: pam_unix(sudo:session): session closed for user root Feb 18 18:54:23 volumio volumio[3620]: error: MPD error: The expression evaluated to a falsy value: Feb 18 18:54:23 volumio volumio[3620]: assert.ok(self.idling) Feb 18 18:54:23 volumio volumio[3620]: error: The expression evaluated to a falsy value: Feb 18 18:54:23 volumio volumio[3620]: assert.ok(self.idling) Feb 18 18:54:23 volumio volumio[3620]: info: MPD running with PID3849 Feb 18 18:54:23 volumio volumio[3620]: ,establishing connection Feb 18 18:54:23 volumio volumio[3620]: error: updateQueue error: null Feb 18 18:54:23 volumio volumio[3620]: info: Completed starting Core Plugins Feb 18 18:54:23 volumio volumio[3620]: info: ------------------------------------------- Feb 18 18:54:23 volumio volumio[3620]: info: ----- MyVolumio plugins startup ---- Feb 18 18:54:23 volumio volumio[3620]: info: ------------------------------------------- Feb 18 18:54:23 volumio volumio[3620]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 18 18:54:23 volumio volumio[3620]: error: updateQueue error: null Feb 18 18:54:23 volumio go-librespot[3959]: time="2026-02-18T18:54:23+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 18:54:23 volumio go-librespot[3959]: time="2026-02-18T18:54:23+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 18:54:23 volumio go-librespot[3959]: time="2026-02-18T18:54:23+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 18:54:23 volumio go-librespot[3959]: time="2026-02-18T18:54:23+07:00" level=info msg="zeroconf server listening on port 45967" Feb 18 18:54:23 volumio go-librespot[3959]: time="2026-02-18T18:54:23+07:00" level=debug msg="obtained new client token: AAC5DC8fBuAVmmTmzUnEh+LUR5SMW9sqW1QigualInmNtecBBH11TwFVg4PVg1RlfQvW4UmYXSA5XpsON0vJ6MxQGfm5OylEoKZzSVqKyTh4jdHyzKXIN6e3y7bmXLSY8A/RUREq0ktgPD2o1q3XvpgjSCVxb3v4RoDBsb5Z9HJAXZn4cHWdHEQm35emFVjw0WsomeggeElqavq6qfYVtTg2qoHPqoQv50WwNTvqd0MD6d5+B0a/t2s+ew==" Feb 18 18:54:23 volumio go-librespot[3959]: time="2026-02-18T18:54:23+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Feb 18 18:54:23 volumio go-librespot[3959]: time="2026-02-18T18:54:23+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:443, retrying with a different AP" error="dial tcp 104.199.241.202:443: connect: connection refused" Feb 18 18:54:24 volumio go-librespot[3959]: time="2026-02-18T18:54:24+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:80, retrying with a different AP" error="dial tcp 104.199.241.202:80: connect: connection refused" Feb 18 18:54:25 volumio go-librespot[3959]: time="2026-02-18T18:54:25+07:00" level=debug msg="connected to ap-guc3.spotify.com:4070" Feb 18 18:54:25 volumio volumio[3620]: info: Initializing connection to go-librespot Websocket Feb 18 18:54:25 volumio go-librespot[3959]: time="2026-02-18T18:54:25+07:00" level=debug msg="new websocket client" Feb 18 18:54:25 volumio volumio[3620]: info: Connection to go-librespot Websocket established Feb 18 18:54:25 volumio go-librespot[3959]: time="2026-02-18T18:54:25+07:00" level=debug msg="completed keyexchange" Feb 18 18:54:25 volumio go-librespot[3959]: time="2026-02-18T18:54:25+07:00" level=debug msg="completed challenge" Feb 18 18:54:25 volumio go-librespot[3959]: time="2026-02-18T18:54:25+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 18:54:25 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 18:54:25 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 18:54:25 volumio volumio[3620]: info: Connection to go-librespot Websocket closed Feb 18 18:54:27 volumio volumio[3620]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 18 18:54:28 volumio volumio[3620]: info: Getting Spotify volume Feb 18 18:54:28 volumio volumio[3620]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 18 18:54:28 volumio volumio[3620]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 18:54:28 volumio volumio[3620]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 18 18:54:28 volumio volumio[3620]: errno: -111, Feb 18 18:54:28 volumio volumio[3620]: code: 'ECONNREFUSED', Feb 18 18:54:28 volumio volumio[3620]: syscall: 'connect', Feb 18 18:54:28 volumio volumio[3620]: address: '127.0.0.1', Feb 18 18:54:28 volumio volumio[3620]: port: 9879, Feb 18 18:54:28 volumio volumio[3620]: response: undefined Feb 18 18:54:28 volumio volumio[3620]: } Feb 18 18:54:28 volumio volumio[3620]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 18 18:54:29 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 18 18:54:29 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 18:54:29 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 18:54:29 volumio go-librespot[3983]: go-librespot daemon starting... Feb 18 18:54:29 volumio go-librespot[3984]: time="2026-02-18T18:54:29+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 18:54:29 volumio go-librespot[3984]: time="2026-02-18T18:54:29+07:00" level=debug msg="app state loaded" Feb 18 18:54:29 volumio go-librespot[3984]: time="2026-02-18T18:54:29+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 18:54:29 volumio go-librespot[3984]: time="2026-02-18T18:54:29+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 18:54:29 volumio go-librespot[3984]: time="2026-02-18T18:54:29+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 18:54:29 volumio go-librespot[3984]: time="2026-02-18T18:54:29+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 18:54:29 volumio go-librespot[3984]: time="2026-02-18T18:54:29+07:00" level=info msg="zeroconf server listening on port 42717" Feb 18 18:54:29 volumio sudo[3993]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-18 18:53' Feb 18 18:54:29 volumio sudo[3993]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 18:54:30 volumio go-librespot[3984]: time="2026-02-18T18:54:30+07:00" level=debug msg="obtained new client token: AAB+zAgsfY9isnlKCbqiTKv806LgAfpLm1A1yFKAruiWCYrL+sDg+BlZqmlnNkz9fJLFq9ZlTNnEsNcWE4Y7f/yi11mr0Iy83vwyBQYGvSxon1vOllj/E/+WBBQIgtxkamUKdLQSzjP2fZfgbjLH3U7Y9Hse8qfSXfMIiJvk3Bqrpjm8J9XOGRfovZdfjaJHH+uOENboKgm609ufBYu7iNqMGYIibPCVX81fW/qA2jAMZYnANHBaq962Mg==" Feb 18 18:54:30 volumio go-librespot[3984]: time="2026-02-18T18:54:30+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 18:54:30 volumio go-librespot[3984]: time="2026-02-18T18:54:30+07:00" level=debug msg="completed keyexchange" Feb 18 18:54:30 volumio go-librespot[3984]: time="2026-02-18T18:54:30+07:00" level=debug msg="completed challenge" Feb 18 18:54:30 volumio sudo[3993]: pam_unix(sudo:session): session closed for user root Feb 18 18:54:30 volumio go-librespot[3984]: time="2026-02-18T18:54:30+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 18:54:30 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 18:54:30 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 18:54:30 volumio volumio-remote-updater[25144]: [2026-02-18 18:54:30] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 18 18:54:30 volumio volumio-remote-updater[25144]: [2026-02-18 18:54:30] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 18 18:54:30 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 18 18:54:30 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 18 18:54:30 volumio systemd[1]: volumio.service: Consumed 49.217s CPU time. Feb 18 18:54:30 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 18 18:54:30 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 18 18:54:30 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 22305. Feb 18 18:54:30 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 18 18:54:30 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 18 18:54:30 volumio systemd[1]: volumio.service: Consumed 49.217s CPU time. Feb 18 18:54:30 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 18 18:54:30 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 18 18:54:33 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 18 18:54:33 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 18:54:33 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 18:54:33 volumio go-librespot[4023]: go-librespot daemon starting... Feb 18 18:54:33 volumio go-librespot[4024]: time="2026-02-18T18:54:33+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 18:54:33 volumio go-librespot[4024]: time="2026-02-18T18:54:33+07:00" level=debug msg="app state loaded" Feb 18 18:54:33 volumio go-librespot[4024]: time="2026-02-18T18:54:33+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 18:54:34 volumio go-librespot[4024]: time="2026-02-18T18:54:34+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 18:54:34 volumio go-librespot[4024]: time="2026-02-18T18:54:34+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 18:54:34 volumio go-librespot[4024]: time="2026-02-18T18:54:34+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 18:54:34 volumio go-librespot[4024]: time="2026-02-18T18:54:34+07:00" level=info msg="zeroconf server listening on port 43927" Feb 18 18:54:34 volumio volumio[4006]: info: ------------------------------------------- Feb 18 18:54:34 volumio volumio[4006]: info: ----- Volumio3 ---- Feb 18 18:54:34 volumio volumio[4006]: info: ------------------------------------------- Feb 18 18:54:34 volumio volumio[4006]: info: ----- System startup ---- Feb 18 18:54:34 volumio volumio[4006]: info: ------------------------------------------- Feb 18 18:54:34 volumio go-librespot[4024]: time="2026-02-18T18:54:34+07:00" level=debug msg="obtained new client token: AADu9CpmcGzoXOF2MXdpVvMXSts+2swUX45oBM3FfwpIR2flhlVZL92TD+kQrfR5WHfls7c5ws02HR5bD3YWsBN88OwBi1ttD2Chq0K8nfcXzcUhic3NLW99+poBxCICA/+8xv1bceBzFaELNcrf3PYwQlXUFJGN9m1tYb4PljvnZFF+osnrWRBNbpgMFc037a6Bj0g5M0jc0/6ynxMrIy03G2r/h0LUqLtgiwJN0fYR4RX02DajwDNzHA==" Feb 18 18:54:34 volumio go-librespot[4024]: time="2026-02-18T18:54:34+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 18:54:34 volumio go-librespot[4024]: time="2026-02-18T18:54:34+07:00" level=debug msg="completed keyexchange" Feb 18 18:54:34 volumio go-librespot[4024]: time="2026-02-18T18:54:34+07:00" level=debug msg="completed challenge" Feb 18 18:54:34 volumio go-librespot[4024]: time="2026-02-18T18:54:34+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 18:54:34 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 18:54:34 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 18:54:35 volumio volumio-remote-updater[25144]: [2026-02-18 18:54:35] [connect] Successful connection Feb 18 18:54:35 volumio volumio[4006]: info: MYVOLUMIO Environment detected Feb 18 18:54:36 volumio volumio[4006]: info: Plugin folders cleanup Feb 18 18:54:36 volumio volumio[4006]: info: Scanning into folder /volumio/app/plugins/ Feb 18 18:54:36 volumio volumio[4006]: info: Scanning category audio_interface Feb 18 18:54:36 volumio volumio[4006]: info: Scanning category miscellanea Feb 18 18:54:36 volumio volumio[4006]: info: Scanning category music_service Feb 18 18:54:36 volumio volumio[4006]: info: Scanning category plugins.json Feb 18 18:54:36 volumio volumio[4006]: info: Scanning category system_controller Feb 18 18:54:36 volumio volumio[4006]: info: Scanning category user_interface Feb 18 18:54:36 volumio volumio[4006]: info: Scanning into folder /data/plugins/ Feb 18 18:54:36 volumio volumio[4006]: info: Scanning category music_service Feb 18 18:54:36 volumio volumio[4006]: info: Plugin folders cleanup completed Feb 18 18:54:36 volumio volumio[4006]: info: ------------------------------------------- Feb 18 18:54:36 volumio volumio[4006]: info: ----- Core plugins startup ---- Feb 18 18:54:36 volumio volumio[4006]: info: ------------------------------------------- Feb 18 18:54:36 volumio volumio[4006]: info: Loading plugins from folder /volumio/app/plugins/ Feb 18 18:54:36 volumio volumio[4006]: info: Adding plugin upnp to MyMusic Plugins Feb 18 18:54:36 volumio volumio[4006]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 18 18:54:36 volumio volumio[4006]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 18 18:54:36 volumio volumio[4006]: info: Loading plugins from folder /data/plugins/ Feb 18 18:54:36 volumio volumio[4006]: info: Loading plugin "system"... Feb 18 18:54:36 volumio volumio[4006]: info: Loading plugin "appearance"... Feb 18 18:54:37 volumio volumio[4006]: info: Loading plugin "network"... Feb 18 18:54:38 volumio volumio[4006]: info: Refreshing Cached IP Addresses Feb 18 18:54:38 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Feb 18 18:54:38 volumio sudo[4044]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 18 18:54:38 volumio sudo[4044]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 18:54:38 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 18:54:38 volumio sudo[4044]: pam_unix(sudo:session): session closed for user root Feb 18 18:54:38 volumio volumio[4006]: info: Loading plugin "services"... Feb 18 18:54:38 volumio sudo[4046]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 18 18:54:38 volumio sudo[4046]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 18:54:38 volumio volumio[4006]: info: Loading plugin "alsa_controller"... Feb 18 18:54:38 volumio sudo[4046]: pam_unix(sudo:session): session closed for user root Feb 18 18:54:38 volumio sudo[4054]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 18 18:54:38 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 18:54:38 volumio sudo[4054]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 18:54:38 volumio go-librespot[4055]: go-librespot daemon starting... Feb 18 18:54:38 volumio go-librespot[4065]: time="2026-02-18T18:54:38+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 18:54:38 volumio go-librespot[4065]: time="2026-02-18T18:54:38+07:00" level=debug msg="app state loaded" Feb 18 18:54:38 volumio go-librespot[4065]: time="2026-02-18T18:54:38+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 18:54:38 volumio volumio[4006]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 18 18:54:38 volumio volumio[4006]: info: Loading plugin "wizard"... Feb 18 18:54:38 volumio volumio[4006]: info: Loading plugin "networkfs"... Feb 18 18:54:38 volumio volumio[4006]: info: Starting Udev Watcher for removable devices Feb 18 18:54:38 volumio volumio[4006]: info: Ignoring mount for partition: boot Feb 18 18:54:38 volumio volumio[4006]: info: Ignoring mount for partition: volumio Feb 18 18:54:38 volumio volumio[4006]: info: Ignoring mount for partition: volumio_data Feb 18 18:54:38 volumio volumio[4006]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 18 18:54:38 volumio volumio[4006]: info: Loading plugin "volumio_command_line_client"... Feb 18 18:54:38 volumio volumio[4006]: info: Loading plugin "upnp"... Feb 18 18:54:38 volumio volumio[4006]: info: [1771415678432] Starting Upmpd Daemon Feb 18 18:54:38 volumio volumio[4006]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 18 18:54:38 volumio volumio[4006]: info: Loading plugin "my_music"... Feb 18 18:54:38 volumio volumio[4006]: info: Loading plugin "mpd"... Feb 18 18:54:38 volumio go-librespot[4065]: time="2026-02-18T18:54:38+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 18 18:54:38 volumio go-librespot[4065]: time="2026-02-18T18:54:38+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 18 18:54:38 volumio go-librespot[4065]: time="2026-02-18T18:54:38+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 18 18:54:38 volumio go-librespot[4065]: time="2026-02-18T18:54:38+07:00" level=info msg="zeroconf server listening on port 33709" Feb 18 18:54:39 volumio go-librespot[4065]: time="2026-02-18T18:54:39+07:00" level=debug msg="obtained new client token: AAD7L3qOYQ3lHDaJHtDjM52AMvj55zxTlVZ2CrQHbLx064MpILyOB7x7Mdp3HZJIFKZ6yU4Sml6YnKOxCtaqxKdBgmMs4wRSFtSmM3ClLqUizp6HI/8J4sBY4OdeBk25rK+Cj/+AzstFZnwjiKI2Ya0jhQgjALkfL8OSe4XrG7fHw/WRw0oqY69HVHboCN2iEbcf6BzadhEg7jY9326Cbw2ESrJXJLKVYjlkIfD464VBii9NYBnSjtLScw==" Feb 18 18:54:39 volumio volumio[4006]: info: Loading plugin "upnp_browser"... Feb 18 18:54:39 volumio go-librespot[4065]: time="2026-02-18T18:54:39+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 18:54:39 volumio go-librespot[4065]: time="2026-02-18T18:54:39+07:00" level=debug msg="completed keyexchange" Feb 18 18:54:39 volumio go-librespot[4065]: time="2026-02-18T18:54:39+07:00" level=debug msg="completed challenge" Feb 18 18:54:39 volumio go-librespot[4065]: time="2026-02-18T18:54:39+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 18:54:39 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 18:54:39 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 18:54:40 volumio sudo[4054]: pam_unix(sudo:session): session closed for user root Feb 18 18:54:42 volumio volumio[4006]: info: Starting UPNP Browser Feb 18 18:54:42 volumio volumio[4006]: info: Loading plugin "alarm-clock"... Feb 18 18:54:42 volumio volumio[4006]: info: Loading plugin "airplay_emulation"... Feb 18 18:54:42 volumio volumio[4006]: info: Starting Shairport Sync Feb 18 18:54:42 volumio volumio[4006]: info: Loading plugin "last_100"... Feb 18 18:54:42 volumio volumio[4006]: info: Loading plugin "webradio"... Feb 18 18:54:42 volumio volumio[4006]: info: Loading plugin "i2s_dacs"... Feb 18 18:54:42 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Feb 18 18:54:42 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 18:54:42 volumio volumio[4006]: info: Loading plugin "volumiodiscovery"... Feb 18 18:54:42 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 18:54:42 volumio go-librespot[4085]: go-librespot daemon starting... Feb 18 18:54:42 volumio volumio[4006]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 18 18:54:42 volumio volumio[4006]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 18:54:42 volumio volumio[4006]: *** WARNING *** For more information see Feb 18 18:54:42 volumio volumio[4006]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 18 18:54:42 volumio volumio[4006]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 18:54:42 volumio volumio[4006]: *** WARNING *** For more information see Feb 18 18:54:42 volumio node[4006]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 18 18:54:42 volumio node[4006]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 18:54:42 volumio node[4006]: *** WARNING *** For more information see Feb 18 18:54:42 volumio node[4006]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 18 18:54:42 volumio node[4006]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 18:54:42 volumio node[4006]: *** WARNING *** For more information see Feb 18 18:54:42 volumio volumio[4006]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 18 18:54:42 volumio volumio[4006]: info: Discovery: Started advertising with name: Volumio Feb 18 18:54:42 volumio go-librespot[4086]: time="2026-02-18T18:54:42+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 18:54:42 volumio go-librespot[4086]: time="2026-02-18T18:54:42+07:00" level=debug msg="app state loaded" Feb 18 18:54:42 volumio go-librespot[4086]: time="2026-02-18T18:54:42+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 18:54:42 volumio volumio[4006]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 18 18:54:42 volumio volumio[4006]: info: Loading plugin "spop"... Feb 18 18:54:43 volumio go-librespot[4086]: time="2026-02-18T18:54:43+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 18:54:43 volumio go-librespot[4086]: time="2026-02-18T18:54:43+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 18:54:43 volumio go-librespot[4086]: time="2026-02-18T18:54:43+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 18:54:43 volumio go-librespot[4086]: time="2026-02-18T18:54:43+07:00" level=info msg="zeroconf server listening on port 37043" Feb 18 18:54:43 volumio go-librespot[4086]: time="2026-02-18T18:54:43+07:00" level=debug msg="obtained new client token: AAAkPolSiqW5L/tdrMKw8zNZGYGGwPpQcWsP40228i4AFRVAFbG3xuNvgkL6xkoeZZsFn7Z5K4zqg5vdaMbfzPZW1xo9Z9B7anLTyceAdWshs3vF62tv2vjV9+SSfjJsUdlX6dd2NO1VEU3UXnfQB6RZmnI2jwMeOyJT0AygWSRw0RfBqjfF060J+FuBC/DZvnoGyc74fLME80s06z6KkGhJow+oUH3RpBtqQeFxkEZdP9cSGDNbMs6BJw==" Feb 18 18:54:43 volumio go-librespot[4086]: time="2026-02-18T18:54:43+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 18:54:43 volumio go-librespot[4086]: time="2026-02-18T18:54:43+07:00" level=debug msg="completed keyexchange" Feb 18 18:54:43 volumio go-librespot[4086]: time="2026-02-18T18:54:43+07:00" level=debug msg="completed challenge" Feb 18 18:54:43 volumio go-librespot[4086]: time="2026-02-18T18:54:43+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 18:54:43 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 18:54:43 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 18:54:44 volumio volumio[4006]: info: Loading plugin "ytcr"... Feb 18 18:54:47 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Feb 18 18:54:47 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 18:54:47 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 18:54:47 volumio go-librespot[4097]: go-librespot daemon starting... Feb 18 18:54:47 volumio go-librespot[4098]: time="2026-02-18T18:54:47+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 18:54:47 volumio go-librespot[4098]: time="2026-02-18T18:54:47+07:00" level=debug msg="app state loaded" Feb 18 18:54:47 volumio go-librespot[4098]: time="2026-02-18T18:54:47+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 18:54:47 volumio volumio[4006]: info: Loading plugin "ytmusic"... Feb 18 18:54:47 volumio go-librespot[4098]: time="2026-02-18T18:54:47+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 18:54:47 volumio go-librespot[4098]: time="2026-02-18T18:54:47+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 18:54:47 volumio go-librespot[4098]: time="2026-02-18T18:54:47+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 18:54:47 volumio go-librespot[4098]: time="2026-02-18T18:54:47+07:00" level=info msg="zeroconf server listening on port 36029" Feb 18 18:54:47 volumio go-librespot[4098]: time="2026-02-18T18:54:47+07:00" level=debug msg="obtained new client token: AACjnxfOKicLCUzDyI5WALkVyja8eKvbbIutVTPqjwHvbxw9RmZutiLb0RhocC5Gk0IxhAsaaSLm75YN4d+3vyf1tuKXb+reTaev6v/4TVnELDucN9S+3DzpdiV91lShIW5pv9oSC4MlnTyyWzXo9Z5fSHjqBZvI9T9YLSz/vOv01JygGs/ekhD9cpbtnceEEkyQJeCg3ChZR6mdesZQ807GP13kOOTHgme4NjrTyaTOhW8ZwvmhpnmxTA==" Feb 18 18:54:47 volumio volumio-remote-updater[25144]: [2026-02-18 18:54:47] [connect] Successful connection Feb 18 18:54:48 volumio go-librespot[4098]: time="2026-02-18T18:54:48+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 18:54:48 volumio go-librespot[4098]: time="2026-02-18T18:54:48+07:00" level=debug msg="completed keyexchange" Feb 18 18:54:48 volumio go-librespot[4098]: time="2026-02-18T18:54:48+07:00" level=debug msg="completed challenge" Feb 18 18:54:48 volumio go-librespot[4098]: time="2026-02-18T18:54:48+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 18:54:48 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 18:54:48 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 18:54:48 volumio volumio[4006]: info: Loading plugin "outputs"... Feb 18 18:54:48 volumio volumio[4006]: info: Loading plugin "albumart"... Feb 18 18:54:48 volumio volumio[4006]: info: Plugin example_plugin is not enabled Feb 18 18:54:48 volumio volumio[4006]: info: Loading plugin "inputs"... Feb 18 18:54:48 volumio volumio[4006]: info: Loading plugin "updater_comm"... Feb 18 18:54:48 volumio volumio[4006]: info: Plugin mpdemulation is not enabled Feb 18 18:54:48 volumio volumio[4006]: info: Loading plugin "rest_api"... Feb 18 18:54:48 volumio volumio[4006]: info: Loading plugin "websocket"... Feb 18 18:54:48 volumio volumio[4006]: info: Starting Socket.io Server version 1.7.4 Feb 18 18:54:48 volumio volumio[4006]: info: Loading plugin "RoonBridge"... Feb 18 18:54:49 volumio volumio[4006]: info: Applying required configuration parameters for plugin RoonBridge Feb 18 18:54:49 volumio volumio[4006]: info: Loading i18n strings for locale en Feb 18 18:54:49 volumio volumio[4006]: Updating browse sources language Feb 18 18:54:49 volumio volumio[4006]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 18:54:49 volumio volumio[4006]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 18 18:54:49 volumio volumio[4006]: info: CoreCommandRouter::initPlayerControls Feb 18 18:54:49 volumio volumio[4006]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 18:54:49 volumio volumio[4006]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 18:54:49 volumio volumio[4006]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 18:54:49 volumio volumio[4006]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 18:54:49 volumio volumio[4006]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 18:54:49 volumio volumio[4006]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 18:54:49 volumio volumio[4006]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 18:54:49 volumio volumio[4006]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 18:54:49 volumio volumio[4121]: Forking 3 albumart workers Feb 18 18:54:49 volumio volumio[4006]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 18 18:54:49 volumio volumio[4006]: Express server listening on port 3000 Feb 18 18:54:49 volumio volumio[4006]: [Metrics] WebUI: 15s 975.46ms Feb 18 18:54:49 volumio volumio[4006]: info: CoreStateMachine::resetVolumioState Feb 18 18:54:49 volumio volumio[4006]: info: CoreStateMachine::getcurrentVolume Feb 18 18:54:49 volumio volumio[4006]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 18:54:49 volumio sudo[4155]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 18 18:54:49 volumio sudo[4155]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 18:54:49 volumio sudo[4155]: pam_unix(sudo:session): session closed for user root Feb 18 18:54:49 volumio sudo[4165]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 18 18:54:49 volumio sudo[4165]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 18:54:49 volumio sudo[4165]: pam_unix(sudo:session): session closed for user root Feb 18 18:54:49 volumio volumio[4006]: info: Volumio Network Manager: Network status updated: 1 Feb 18 18:54:50 volumio volumio[4006]: info: VolumeController:: Volume=100 Mute =false Feb 18 18:54:50 volumio volumio[4006]: info: CoreStateMachine::pushState Feb 18 18:54:50 volumio volumio[4006]: info: CorePlayQueue::getTrack 0 Feb 18 18:54:50 volumio volumio[4006]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 18 18:54:50 volumio volumio[4006]: info: CoreCommandRouter::volumioPushState Feb 18 18:54:50 volumio volumio[4006]: info: CoreStateMachine::updateTrackBlock Feb 18 18:54:50 volumio volumio[4006]: info: CorePlayQueue::getTrackBlock Feb 18 18:54:50 volumio volumio[4006]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 18:54:50 volumio volumio-remote-updater[25144]: [2026-02-18 18:54:50] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1771415687 101 Feb 18 18:54:50 volumio volumio[4006]: 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 Feb 18 18:54:50 volumio volumio[4006]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 18:54:50 volumio volumio[4006]: info: Reloading queue from file Feb 18 18:54:50 volumio volumio[4006]: info: CoreStateMachine::setRepeat null single undefined Feb 18 18:54:50 volumio volumio[4006]: info: CoreStateMachine::pushState Feb 18 18:54:50 volumio volumio[4006]: info: CorePlayQueue::getTrack 0 Feb 18 18:54:50 volumio volumio[4006]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 18 18:54:50 volumio volumio[4006]: info: CoreCommandRouter::volumioPushState Feb 18 18:54:50 volumio volumio[4006]: info: CoreStateMachine::setRandom null Feb 18 18:54:50 volumio volumio[4006]: info: CoreStateMachine::pushState Feb 18 18:54:50 volumio volumio[4006]: info: CorePlayQueue::getTrack 0 Feb 18 18:54:50 volumio volumio[4006]: info: CoreCommandRouter::volumioPushState Feb 18 18:54:50 volumio volumio[4006]: info: Setting Device type: Raspberry PI Feb 18 18:54:50 volumio volumio[4006]: info: Completed loading Core Plugins Feb 18 18:54:50 volumio volumio[4006]: info: Preparing to generate the ALSA configuration file Feb 18 18:54:50 volumio volumio[4006]: info: VolumeController:: Volume=100 Mute =false Feb 18 18:54:50 volumio volumio[4006]: info: CoreStateMachine::pushState Feb 18 18:54:50 volumio volumio[4006]: info: CorePlayQueue::getTrack 0 Feb 18 18:54:50 volumio volumio[4006]: info: CoreCommandRouter::volumioPushState Feb 18 18:54:50 volumio volumio[4006]: info: Asound.conf file unchanged, so no further update is needed Feb 18 18:54:50 volumio volumio[4006]: info: Output device has changed, restarting MPD Feb 18 18:54:50 volumio sudo[4182]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 18 18:54:50 volumio sudo[4182]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 18:54:50 volumio volumio[4006]: info: Output device has changed, restarting Shairport Sync Feb 18 18:54:50 volumio volumio[4006]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 18:54:50 volumio volumio[4006]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 18:54:50 volumio sudo[4185]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 18 18:54:50 volumio sudo[4185]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 18:54:50 volumio sudo[4185]: pam_unix(sudo:session): session closed for user root Feb 18 18:54:50 volumio sudo[4188]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 18 18:54:50 volumio sudo[4188]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 18:54:50 volumio volumio[4006]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 18 18:54:50 volumio volumio[4006]: info: ___________ START PLUGINS ___________ Feb 18 18:54:50 volumio sudo[4182]: pam_unix(sudo:session): session closed for user root Feb 18 18:54:50 volumio volumio[4006]: info: ControllerMpd::onStart: Initializing MPD Feb 18 18:54:50 volumio volumio[4006]: info: Creating MPD Configuration file Feb 18 18:54:50 volumio volumio[4006]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 18 18:54:50 volumio volumio[4006]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 18:54:50 volumio volumio[4006]: info: [1771415690925] CoreMusicLibrary::Adding element Media Servers Feb 18 18:54:50 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 18 18:54:50 volumio volumio[4006]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 18:54:50 volumio volumio[4006]: info: UPNP Browser: Client initialized successfully Feb 18 18:54:51 volumio sudo[4198]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 18 18:54:51 volumio sudo[4198]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 18:54:51 volumio sudo[4197]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 18 18:54:51 volumio volumio[4006]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 18:54:51 volumio volumio[4006]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 18:54:51 volumio sudo[4197]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 18:54:51 volumio sudo[4197]: pam_unix(sudo:session): session closed for user root Feb 18 18:54:51 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 18 18:54:51 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 18 18:54:51 volumio systemd[1]: mpd.service: Consumed 7.209s CPU time. Feb 18 18:54:51 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 18 18:54:51 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 18 18:54:51 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 18 18:54:51 volumio volumio[4006]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 18 18:54:51 volumio volumio[4006]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 18:54:51 volumio volumio[4006]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 18:54:51 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 18 18:54:51 volumio volumio[4006]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 18 18:54:51 volumio volumio[4006]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 18:54:51 volumio volumio[4006]: info: [1771415691244] CoreMusicLibrary::Adding element Last_100 Feb 18 18:54:51 volumio volumio[4006]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 18:54:51 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 18 18:54:51 volumio volumio[4006]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 18:54:51 volumio volumio[4006]: info: [1771415691263] CoreMusicLibrary::Adding element Webradio Feb 18 18:54:51 volumio volumio[4006]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 18:54:51 volumio volumio[4006]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 18 18:54:51 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Feb 18 18:54:51 volumio volumio[4006]: info: Initializing BBC Radios Feb 18 18:54:51 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 18:54:51 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 18:54:51 volumio go-librespot[4212]: go-librespot daemon starting... Feb 18 18:54:51 volumio go-librespot[4214]: time="2026-02-18T18:54:51+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 18:54:51 volumio go-librespot[4214]: time="2026-02-18T18:54:51+07:00" level=debug msg="app state loaded" Feb 18 18:54:51 volumio go-librespot[4214]: time="2026-02-18T18:54:51+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 18:54:51 volumio volumio[4006]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 18 18:54:51 volumio volumio[4006]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 18:54:51 volumio volumio[4006]: info: Creating Spotify config file Feb 18 18:54:51 volumio volumio[4006]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 18:54:51 volumio sudo[4210]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 18 18:54:51 volumio sudo[4210]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 18 18:54:51 volumio sudo[4210]: pam_unix(sudo:session): session closed for user root Feb 18 18:54:52 volumio go-librespot[4214]: time="2026-02-18T18:54:52+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 18:54:52 volumio go-librespot[4214]: time="2026-02-18T18:54:52+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 18:54:52 volumio go-librespot[4214]: time="2026-02-18T18:54:52+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 18:54:52 volumio go-librespot[4214]: time="2026-02-18T18:54:52+07:00" level=info msg="zeroconf server listening on port 36113" Feb 18 18:54:52 volumio go-librespot[4214]: time="2026-02-18T18:54:52+07:00" level=debug msg="obtained new client token: AACYZY3DkyIyGFCnEkrxZZMuF4lfYGRfyVFkWlXcVhmNPEfntoi7EZKYne1xXRH6+BkIXEEK41JrX/kZJN6BnfZ9U8vD1TeJt4Dn/ozAZWbRrFgbeZifLX9oZE4aWYoh6OKw+EyHqEZQ35Nbv1AMvwX0xD649xmzCAiKYv76SL2RHNNMiIyhA4Uaxl0qm15ICmQMa1yNnQchIA5P6ZCwjZIjFtCeRwNgl1ILS4K87eooP0ao7N4b7bVxeQ==" Feb 18 18:54:52 volumio go-librespot[4214]: time="2026-02-18T18:54:52+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 18:54:52 volumio go-librespot[4214]: time="2026-02-18T18:54:52+07:00" level=debug msg="completed keyexchange" Feb 18 18:54:52 volumio go-librespot[4214]: time="2026-02-18T18:54:52+07:00" level=debug msg="completed challenge" Feb 18 18:54:52 volumio go-librespot[4214]: time="2026-02-18T18:54:52+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 18:54:52 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 18:54:52 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 18:54:52 volumio volumio[4006]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 18:54:52 volumio volumio[4006]: info: [1771415692928] CoreMusicLibrary::Adding element YouTube Music Feb 18 18:54:52 volumio volumio[4006]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 18:54:52 volumio volumio[4006]: Cannot find translation for source YouTube Music Feb 18 18:54:52 volumio volumio[4134]: Starting albumart workers Feb 18 18:54:53 volumio volumio[4006]: info: Volumio Calling Home Feb 18 18:54:53 volumio sudo[4235]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 18 18:54:53 volumio sudo[4235]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 18:54:53 volumio sudo[4235]: pam_unix(sudo:session): session closed for user root Feb 18 18:54:53 volumio volumio[4131]: Starting albumart workers Feb 18 18:54:53 volumio volumio[4136]: Starting albumart workers Feb 18 18:54:53 volumio volumio[4006]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 18 18:54:53 volumio volumio[4006]: info: Discovery: Found device Volumio Feb 18 18:54:53 volumio volumio[4006]: info: CoreCommandRouter::volumioGetState Feb 18 18:54:53 volumio volumio[4006]: info: CorePlayQueue::getTrack 0 Feb 18 18:54:53 volumio volumio[4006]: info: MPD Permissions set Feb 18 18:54:53 volumio volumio[4006]: info: MPD Permissions set Feb 18 18:54:53 volumio volumio[4006]: info: Upmpdcli Daemon Started Feb 18 18:54:54 volumio volumio[4006]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 18 18:54:54 volumio volumio[4006]: info: Discovery: Found device Volumio Feb 18 18:54:54 volumio volumio[4006]: info: CoreCommandRouter::volumioGetState Feb 18 18:54:54 volumio volumio[4006]: info: CorePlayQueue::getTrack 0 Feb 18 18:54:54 volumio volumio[4006]: info: Spotify config file written Feb 18 18:54:54 volumio volumio[4006]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Feb 18 18:54:54 volumio volumio[4006]: info: Volumio called home Feb 18 18:54:54 volumio volumio[4006]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 18:54:54 volumio volumio[4006]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 18:54:54 volumio volumio[4006]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 18:54:54 volumio volumio[4006]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 18:54:54 volumio volumio[4006]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 18:54:54 volumio volumio[4006]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 18:54:54 volumio volumio[4006]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 18:54:54 volumio volumio[4006]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 18:54:54 volumio sudo[4241]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 18 18:54:54 volumio volumio[4006]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 18:54:54 volumio sudo[4241]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 18:54:54 volumio volumio[4006]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 18:54:54 volumio volumio[4006]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 18:54:54 volumio volumio[4006]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 18:54:54 volumio volumio[4006]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 18:54:54 volumio volumio[4006]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 18:54:54 volumio volumio[4006]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 18:54:54 volumio volumio[4006]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 18:54:54 volumio volumio[4006]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 18:54:54 volumio volumio[4006]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 18:54:54 volumio volumio[4006]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 18:54:54 volumio volumio[4006]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 18:54:54 volumio volumio[4006]: info: No need to fix Spotify hosts Feb 18 18:54:54 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 18:54:54 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 18:54:54 volumio go-librespot[4253]: go-librespot daemon starting... Feb 18 18:54:54 volumio sudo[4241]: pam_unix(sudo:session): session closed for user root Feb 18 18:54:54 volumio go-librespot[4254]: time="2026-02-18T18:54:54+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 18:54:54 volumio go-librespot[4254]: time="2026-02-18T18:54:54+07:00" level=debug msg="app state loaded" Feb 18 18:54:54 volumio go-librespot[4254]: time="2026-02-18T18:54:54+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 18:54:55 volumio go-librespot[4254]: time="2026-02-18T18:54:55+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 18 18:54:55 volumio go-librespot[4254]: time="2026-02-18T18:54:55+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 18 18:54:55 volumio go-librespot[4254]: time="2026-02-18T18:54:55+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 18 18:54:55 volumio go-librespot[4254]: time="2026-02-18T18:54:55+07:00" level=info msg="zeroconf server listening on port 39119" Feb 18 18:54:55 volumio go-librespot[4254]: time="2026-02-18T18:54:55+07:00" level=debug msg="obtained new client token: AABQM3L2KchyRlo6vxgC1qrwH2AEFeeIeHaLD53CQpCAGJkq7N4FfrLboP93p/XLUWuxCdoMnLk2GCZapyX9fZ8/ecPkKJGpTAzfr3/VL8eX00Q99NtLxCiJ3NZafj+Moz3OUvUiM3f0amX1AjV1ioQ7gpNzhEeDT9254A9ya/trfR95nx23Gz2oezpASTxlo2GRQVd5Gpwfick1QcJtrsu7aUEG/q5cnTHt5NKFHmZ3MR9j/LyRPiTYvg==" Feb 18 18:54:55 volumio go-librespot[4254]: time="2026-02-18T18:54:55+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 18:54:55 volumio volumio[4006]: info: Starting Shairport Sync Feb 18 18:54:55 volumio go-librespot[4254]: time="2026-02-18T18:54:55+07:00" level=debug msg="completed keyexchange" Feb 18 18:54:55 volumio go-librespot[4254]: time="2026-02-18T18:54:55+07:00" level=debug msg="completed challenge" Feb 18 18:54:55 volumio volumio[4006]: info: Starting Shairport Sync Feb 18 18:54:55 volumio volumio[4006]: info: Starting Shairport Sync Feb 18 18:54:55 volumio sudo[4281]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 18:54:55 volumio go-librespot[4254]: time="2026-02-18T18:54:55+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 18:54:55 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 18:54:55 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 18:54:55 volumio sudo[4281]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 18:54:55 volumio sudo[4283]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 18:54:55 volumio sudo[4283]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 18:54:55 volumio sudo[4285]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 18:54:55 volumio sudo[4285]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 18:54:55 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 18 18:54:55 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 18 18:54:55 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 18:54:55 volumio systemd[1]: shairport-sync.service: Consumed 2.240s CPU time. Feb 18 18:54:56 volumio volumio[4006]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 18 18:54:56 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 18:54:56 volumio volumio[4006]: SPOTIFY: BQDJx0YLcxFuAqoUk9DcsW_YPUrDIHPcP7Z3Y23SJqvczMuczjvZdUKh72Zg-0xjvSZuR7dLyZLDXEOx6Ts9pWGO1ViBT6R4r5PfwNW_pD1OrIc58GT_T2jLKjxJC9cjvHr19I632N5jji4jELNbp91W-8_Bx46oe0N7wELxJjjsInch4MIJ3ikMM171-1Xj6CInACaaGCNizgEPHKlxpC4UtvczBv7ebxRHhSObuH32NRQL83Hd0BxVhtQ6zft6D1vs0iuXlTaJytnZSkcxYbVj0dvtVdq4Suq8PWiihcu5maBgGfByXH8J Feb 18 18:54:56 volumio volumio[4006]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 18 18:54:56 volumio volumio[4006]: info: New Spotify access token = BQDJx0YLcxFuAqoUk9DcsW_YPUrDIHPcP7Z3Y23SJqvczMuczjvZdUKh72Zg-0xjvSZuR7dLyZLDXEOx6Ts9pWGO1ViBT6R4r5PfwNW_pD1OrIc58GT_T2jLKjxJC9cjvHr19I632N5jji4jELNbp91W-8_Bx46oe0N7wELxJjjsInch4MIJ3ikMM171-1Xj6CInACaaGCNizgEPHKlxpC4UtvczBv7ebxRHhSObuH32NRQL83Hd0BxVhtQ6zft6D1vs0iuXlTaJytnZSkcxYbVj0dvtVdq4Suq8PWiihcu5maBgGfByXH8J Feb 18 18:54:56 volumio volumio[4006]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 18 18:54:56 volumio sudo[4281]: pam_unix(sudo:session): session closed for user root Feb 18 18:54:56 volumio sudo[4285]: pam_unix(sudo:session): session closed for user root Feb 18 18:54:56 volumio volumio[4006]: info: CoreCommandRouter::volumioGetState Feb 18 18:54:56 volumio volumio[4006]: info: CorePlayQueue::getTrack 0 Feb 18 18:54:56 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 18 18:54:56 volumio volumio[4006]: info: Shairport-Sync Started Feb 18 18:54:56 volumio volumio[4006]: Error adding Membership: Error: addMembership EINVAL Feb 18 18:54:56 volumio volumio[4006]: info: Shairport-Sync Started Feb 18 18:54:56 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 18 18:54:56 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 18:54:56 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 18:54:56 volumio sudo[4283]: pam_unix(sudo:session): session closed for user root Feb 18 18:54:56 volumio volumio[4006]: info: Shairport-Sync Started Feb 18 18:54:56 volumio volumio[4006]: SPOTIFY: User informations: {"country":"PK","display_name":"215mmgea6kss3jxeqsqdquvji","email":"linh.ngotran@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/215mmgea6kss3jxeqsqdquvji"},"followers":{"href":null,"total":1},"href":"https://api.spotify.com/v1/users/215mmgea6kss3jxeqsqdquvji","id":"215mmgea6kss3jxeqsqdquvji","images":[],"product":"premium","type":"user","uri":"spotify:user:215mmgea6kss3jxeqsqdquvji"} Feb 18 18:54:56 volumio volumio[4006]: info: Spotify Successfully logged in Feb 18 18:54:56 volumio volumio[4006]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 18:54:56 volumio volumio[4006]: info: [1771415696658] CoreMusicLibrary::Adding element Spotify Feb 18 18:54:56 volumio volumio[4006]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 18:54:56 volumio volumio[4006]: Cannot find translation for source YouTube Music Feb 18 18:54:56 volumio volumio[4006]: Cannot find translation for source Spotify Feb 18 18:54:57 volumio volumio[4006]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 18 18:54:57 volumio volumio[4006]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 18:54:57 volumio volumio[4006]: info: VolumeController:: Volume=100 Mute =false Feb 18 18:54:57 volumio volumio[4006]: info: CoreCommandRouter::volumioGetState Feb 18 18:54:57 volumio volumio[4006]: info: CorePlayQueue::getTrack 0 Feb 18 18:54:57 volumio volumio[4006]: info: CoreStateMachine::pushState Feb 18 18:54:57 volumio volumio[4006]: info: CorePlayQueue::getTrack 0 Feb 18 18:54:57 volumio volumio[4006]: info: CoreCommandRouter::volumioPushState Feb 18 18:54:58 volumio volumio[4006]: info: go-librespot daemon successfully initialized Feb 18 18:54:58 volumio mpd[4232]: 2026-02-18T18:54:58 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 18 18:54:58 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 18 18:54:58 volumio sudo[4188]: pam_unix(sudo:session): session closed for user root Feb 18 18:54:58 volumio sudo[4198]: pam_unix(sudo:session): session closed for user root Feb 18 18:54:58 volumio volumio[4006]: error: MPD error: The expression evaluated to a falsy value: Feb 18 18:54:58 volumio volumio[4006]: assert.ok(self.idling) Feb 18 18:54:58 volumio volumio[4006]: error: The expression evaluated to a falsy value: Feb 18 18:54:58 volumio volumio[4006]: assert.ok(self.idling) Feb 18 18:54:58 volumio volumio[4006]: info: MPD running with PID4232 Feb 18 18:54:58 volumio volumio[4006]: ,establishing connection Feb 18 18:54:58 volumio volumio[4006]: error: updateQueue error: null Feb 18 18:54:59 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Feb 18 18:54:59 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 18:54:59 volumio volumio[4006]: info: Completed starting Core Plugins Feb 18 18:54:59 volumio volumio[4006]: info: ------------------------------------------- Feb 18 18:54:59 volumio volumio[4006]: info: ----- MyVolumio plugins startup ---- Feb 18 18:54:59 volumio volumio[4006]: info: ------------------------------------------- Feb 18 18:54:59 volumio volumio[4006]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 18 18:54:59 volumio volumio[4006]: error: updateQueue error: null Feb 18 18:54:59 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 18:54:59 volumio go-librespot[4326]: go-librespot daemon starting... Feb 18 18:54:59 volumio go-librespot[4327]: time="2026-02-18T18:54:59+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 18:54:59 volumio go-librespot[4327]: time="2026-02-18T18:54:59+07:00" level=debug msg="app state loaded" Feb 18 18:54:59 volumio go-librespot[4327]: time="2026-02-18T18:54:59+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 18:54:59 volumio go-librespot[4327]: time="2026-02-18T18:54:59+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 18:54:59 volumio go-librespot[4327]: time="2026-02-18T18:54:59+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 18:54:59 volumio go-librespot[4327]: time="2026-02-18T18:54:59+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 18:54:59 volumio go-librespot[4327]: time="2026-02-18T18:54:59+07:00" level=info msg="zeroconf server listening on port 43413" Feb 18 18:54:59 volumio go-librespot[4327]: time="2026-02-18T18:54:59+07:00" level=debug msg="obtained new client token: AABp62OmBuU/pSQzowQYKsw+8VGT4zgwQPEfLxMf8bAT18sXRGuXwoWfJkMffHEckkVtEjrn82JBqgQDD7G20mZsNDYm1BB+W+h0IgDD08UdvXePTSu5UG1UpGmt8lPOVbjOBW/9XWXHox11URPkmfBx1oklmRXKNtmntKE5DVJqI/CWZG+9YVxyS3xF0dBQNu7iBkEotDNlEtxgA82WVLqFvdpWEnYUGpUS3r+P5RDaJaKvmvB9AOzdjQ==" Feb 18 18:54:59 volumio go-librespot[4327]: time="2026-02-18T18:54:59+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 18:55:00 volumio go-librespot[4327]: time="2026-02-18T18:55:00+07:00" level=debug msg="completed keyexchange" Feb 18 18:55:00 volumio go-librespot[4327]: time="2026-02-18T18:55:00+07:00" level=debug msg="completed challenge" Feb 18 18:55:00 volumio go-librespot[4327]: time="2026-02-18T18:55:00+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 18:55:00 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 18:55:00 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 18:55:01 volumio volumio[4006]: info: Initializing connection to go-librespot Websocket Feb 18 18:55:01 volumio volumio[4006]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 18:55:03 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Feb 18 18:55:03 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 18:55:03 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 18:55:03 volumio go-librespot[4335]: go-librespot daemon starting... Feb 18 18:55:03 volumio go-librespot[4336]: time="2026-02-18T18:55:03+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 18:55:03 volumio go-librespot[4336]: time="2026-02-18T18:55:03+07:00" level=debug msg="app state loaded" Feb 18 18:55:03 volumio go-librespot[4336]: time="2026-02-18T18:55:03+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 18:55:03 volumio volumio[4006]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 18 18:55:03 volumio go-librespot[4336]: time="2026-02-18T18:55:03+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 18:55:03 volumio go-librespot[4336]: time="2026-02-18T18:55:03+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 18:55:03 volumio go-librespot[4336]: time="2026-02-18T18:55:03+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 18:55:03 volumio go-librespot[4336]: time="2026-02-18T18:55:03+07:00" level=info msg="zeroconf server listening on port 33493" Feb 18 18:55:04 volumio go-librespot[4336]: time="2026-02-18T18:55:04+07:00" level=debug msg="obtained new client token: AADC+YFooHfyM4MWwG+7PYtXLGPJ/FHqV/7iATtH1ttT3wFnxOT4kxZu4lPKRr4RQqkq5yymFfRopPsHu0WJCuUqF0/FxudNapZREu0xt7F+L7jz0+oBGZcJmr+shoMj1Pp7uJze10eOroK10yo2ssuKkXbNWeRmX9eECwO53mb925ilx3toPl2CzbcmWiIZmD/qx1ypldV76uJWpk0gVO1qWvBe89F5uhvuoXh6HDMptdvfq2oG6a0=" Feb 18 18:55:04 volumio go-librespot[4336]: time="2026-02-18T18:55:04+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 18:55:04 volumio go-librespot[4336]: time="2026-02-18T18:55:04+07:00" level=debug msg="completed keyexchange" Feb 18 18:55:04 volumio go-librespot[4336]: time="2026-02-18T18:55:04+07:00" level=debug msg="completed challenge" Feb 18 18:55:04 volumio go-librespot[4336]: time="2026-02-18T18:55:04+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 18:55:04 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 18:55:04 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 18:55:04 volumio volumio[4006]: info: Initializing connection to go-librespot Websocket Feb 18 18:55:04 volumio volumio[4006]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 18:55:07 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Feb 18 18:55:07 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 18:55:07 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 18:55:07 volumio go-librespot[4343]: go-librespot daemon starting... Feb 18 18:55:07 volumio go-librespot[4344]: time="2026-02-18T18:55:07+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 18:55:07 volumio go-librespot[4344]: time="2026-02-18T18:55:07+07:00" level=debug msg="app state loaded" Feb 18 18:55:07 volumio go-librespot[4344]: time="2026-02-18T18:55:07+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 18:55:07 volumio volumio[4006]: info: Initializing connection to go-librespot Websocket Feb 18 18:55:07 volumio go-librespot[4344]: time="2026-02-18T18:55:07+07:00" level=debug msg="new websocket client" Feb 18 18:55:07 volumio volumio[4006]: info: Connection to go-librespot Websocket established Feb 18 18:55:08 volumio volumio[4006]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 18 18:55:08 volumio volumio[4006]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 18 18:55:08 volumio volumio[4006]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 18 18:55:08 volumio volumio[4006]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 18 18:55:08 volumio volumio[4006]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 18 18:55:08 volumio volumio[4006]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 18 18:55:08 volumio volumio[4006]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 18 18:55:08 volumio volumio[4006]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 18 18:55:08 volumio volumio[4006]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 18 18:55:08 volumio volumio[4006]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 18 18:55:08 volumio volumio[4006]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 18 18:55:08 volumio volumio[4006]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 18 18:55:08 volumio volumio[4006]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 18 18:55:08 volumio volumio[4006]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 18 18:55:08 volumio volumio[4006]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 18 18:55:08 volumio volumio[4006]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 18 18:55:08 volumio volumio[4006]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 18 18:55:08 volumio volumio[4006]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 18 18:55:08 volumio volumio[4006]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 18 18:55:08 volumio volumio[4006]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 18 18:55:08 volumio volumio[4006]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 18 18:55:08 volumio volumio[4006]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 18 18:55:08 volumio volumio[4006]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 18 18:55:08 volumio volumio[4006]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 18 18:55:08 volumio volumio[4006]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 18 18:55:08 volumio volumio[4006]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 18 18:55:08 volumio volumio[4006]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 18 18:55:08 volumio volumio[4006]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 18 18:55:08 volumio go-librespot[4344]: time="2026-02-18T18:55:08+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 18:55:08 volumio volumio[4006]: info: Adding plugin bluetooth to MyMusic Plugins Feb 18 18:55:08 volumio go-librespot[4344]: time="2026-02-18T18:55:08+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 18:55:08 volumio go-librespot[4344]: time="2026-02-18T18:55:08+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 18:55:08 volumio volumio[4006]: info: Adding plugin multiroom to MyMusic Plugins Feb 18 18:55:08 volumio volumio[4006]: info: Adding plugin metavolumio to MyMusic Plugins Feb 18 18:55:08 volumio volumio[4006]: info: Adding plugin cd_controller to MyMusic Plugins Feb 18 18:55:08 volumio volumio[4006]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 18 18:55:08 volumio volumio[4006]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 18 18:55:08 volumio volumio[4006]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 18 18:55:08 volumio volumio[4006]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 18 18:55:08 volumio go-librespot[4344]: time="2026-02-18T18:55:08+07:00" level=info msg="zeroconf server listening on port 45801" Feb 18 18:55:08 volumio go-librespot[4344]: time="2026-02-18T18:55:08+07:00" level=debug msg="obtained new client token: AACeHgnMzMamu/VEr8tbz3DAShfhAjbjlRVAOpYYUilfZ+ZLC0ie4UxXvVfOc7G0y11TURVkN1xketEZTBL1bc9eRJgKQuWXlaXhe5X47lVPmT+Y4pZXcvThKyCtVZbjGKLwTde1IVd8XF6/PNyux+oLIFp51T2DbM5Hxrc9JwGuQhQfiyp1mgcurKy3Z0XOgWo6l5AMpSwdzOYBMeCH/GwiTAUojFvScYRUs9JAnaGSSsQMtenbRwTn0Q==" Feb 18 18:55:08 volumio go-librespot[4344]: time="2026-02-18T18:55:08+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 18:55:08 volumio go-librespot[4344]: time="2026-02-18T18:55:08+07:00" level=debug msg="completed keyexchange" Feb 18 18:55:08 volumio go-librespot[4344]: time="2026-02-18T18:55:08+07:00" level=debug msg="completed challenge" Feb 18 18:55:08 volumio go-librespot[4344]: time="2026-02-18T18:55:08+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 18:55:08 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 18:55:08 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 18:55:09 volumio volumio[4006]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 18 18:55:09 volumio volumio[4006]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 18 18:55:09 volumio volumio[4006]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 18:55:09 volumio volumio[4006]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 18:55:09 volumio volumio[4006]: info: Starting MyVolumio Remote Streaming Endpoints Feb 18 18:55:10 volumio volumio[4006]: info: MyVolumio login type: Token Feb 18 18:55:10 volumio volumio[4006]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 18 18:55:10 volumio volumio[4006]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 18 18:55:11 volumio volumio[4006]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 18 18:55:11 volumio volumio[4006]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 18 18:55:11 volumio volumio[4006]: info: Streaming services startup Feb 18 18:55:11 volumio volumio[4006]: info: Starting Streaming Daemon Feb 18 18:55:11 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Feb 18 18:55:11 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 18:55:11 volumio sudo[4367]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 18 18:55:11 volumio volumio[4006]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 18 18:55:11 volumio sudo[4367]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 18:55:11 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 18:55:11 volumio go-librespot[4372]: go-librespot daemon starting... Feb 18 18:55:11 volumio sudo[4367]: pam_unix(sudo:session): session closed for user root Feb 18 18:55:11 volumio go-librespot[4374]: time="2026-02-18T18:55:11+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 18:55:11 volumio go-librespot[4374]: time="2026-02-18T18:55:11+07:00" level=debug msg="app state loaded" Feb 18 18:55:11 volumio go-librespot[4374]: time="2026-02-18T18:55:11+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 18:55:11 volumio volumio[4006]: info: Getting Spotify volume Feb 18 18:55:12 volumio volumio[4006]: info: Connection to go-librespot Websocket closed Feb 18 18:55:12 volumio volumio[4006]: error: Cannot start Volumio Streaming Daemon Feb 18 18:55:12 volumio volumio[4006]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 18 18:55:12 volumio volumio[4006]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 18 18:55:12 volumio volumio[4006]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Feb 18 18:55:12 volumio volumio[4006]: info: CoreCommandRouter::volumioGetState Feb 18 18:55:12 volumio volumio[4006]: info: CorePlayQueue::getTrack 0 Feb 18 18:55:12 volumio volumio[4006]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 18 18:55:12 volumio volumio[4006]: SPOTIFY: SPOTIFY VOLUME undefined Feb 18 18:55:12 volumio volumio[4006]: SPOTIFY: VOLUMIO VOLUME 100 Feb 18 18:55:12 volumio volumio[4006]: info: Aligning Spotify Volume to Volumio Volume Feb 18 18:55:12 volumio volumio[4006]: info: CoreCommandRouter::volumioGetState Feb 18 18:55:12 volumio volumio[4006]: info: CorePlayQueue::getTrack 0 Feb 18 18:55:12 volumio volumio[4006]: info: Setting Spotify Volume from Volumio: 100 Feb 18 18:55:12 volumio go-librespot[4374]: time="2026-02-18T18:55:12+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 18:55:12 volumio go-librespot[4374]: time="2026-02-18T18:55:12+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 18:55:12 volumio go-librespot[4374]: time="2026-02-18T18:55:12+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 18:55:12 volumio go-librespot[4374]: time="2026-02-18T18:55:12+07:00" level=info msg="zeroconf server listening on port 45763" Feb 18 18:55:12 volumio go-librespot[4374]: time="2026-02-18T18:55:12+07:00" level=debug msg="obtained new client token: AABCvL1MG+iG7Z6rcixlalWZ824q79p473M3ay1ChGd15NkHjqaFi8mS8WqPycCZxdBhp3NQ2sQEazkrJ8kF6n4mWiNj+besd6VpPzDIRkqXxDZT9MwWaawdTdBW0Opx5VqIwwkLBx/it9L2N/uLxpOjc2Dw8wHPvYXfdjsBleef3Js5Si9Eh5RBNpvLk99zam/UQMWE+mdz0Pxxm7VFNdyiPFxg5nyHE21nNZrZ3DIn40hGdVVJx17oCw==" Feb 18 18:55:12 volumio go-librespot[4374]: time="2026-02-18T18:55:12+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 18:55:12 volumio go-librespot[4374]: time="2026-02-18T18:55:12+07:00" level=debug msg="completed keyexchange" Feb 18 18:55:12 volumio go-librespot[4374]: time="2026-02-18T18:55:12+07:00" level=debug msg="completed challenge" Feb 18 18:55:13 volumio go-librespot[4374]: time="2026-02-18T18:55:13+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 18:55:13 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 18:55:13 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 18:55:13 volumio volumio[4006]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 18 18:55:13 volumio volumio[4006]: Error: socket hang up Feb 18 18:55:13 volumio volumio[4006]: at connResetException (node:internal/errors:720:14) Feb 18 18:55:13 volumio volumio[4006]: at Socket.socketOnEnd (node:_http_client:519:23) Feb 18 18:55:13 volumio volumio[4006]: at Socket.emit (node:events:526:35) Feb 18 18:55:13 volumio volumio[4006]: at endReadableNT (node:internal/streams/readable:1376:12) Feb 18 18:55:13 volumio volumio[4006]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Feb 18 18:55:13 volumio volumio[4006]: code: 'ECONNRESET', Feb 18 18:55:13 volumio volumio[4006]: response: undefined Feb 18 18:55:13 volumio volumio[4006]: } Feb 18 18:55:13 volumio volumio[4006]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 18 18:55:14 volumio sudo[4396]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-18 18:54' Feb 18 18:55:14 volumio sudo[4396]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 18:55:14 volumio sudo[4396]: pam_unix(sudo:session): session closed for user root Feb 18 18:55:16 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Feb 18 18:55:16 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 18:55:16 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 18:55:16 volumio go-librespot[4404]: go-librespot daemon starting... Feb 18 18:55:16 volumio go-librespot[4405]: time="2026-02-18T18:55:16+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 18:55:16 volumio go-librespot[4405]: time="2026-02-18T18:55:16+07:00" level=debug msg="app state loaded" Feb 18 18:55:16 volumio go-librespot[4405]: time="2026-02-18T18:55:16+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 18:55:16 volumio volumio-remote-updater[25144]: [2026-02-18 18:55:16] [error] handle_read_frame error: asio.system:104 (Connection reset by peer) Feb 18 18:55:16 volumio volumio-remote-updater[25144]: [2026-02-18 18:55:16] [disconnect] Disconnect close local:[1006,Connection reset by peer] remote:[1006] Feb 18 18:55:16 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 18 18:55:16 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 18 18:55:16 volumio systemd[1]: volumio.service: Consumed 55.789s CPU time. Feb 18 18:55:16 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 18 18:55:16 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 18 18:55:16 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 22306. Feb 18 18:55:16 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 18 18:55:16 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 18 18:55:16 volumio systemd[1]: volumio.service: Consumed 55.789s CPU time. Feb 18 18:55:16 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 18 18:55:16 volumio go-librespot[4405]: time="2026-02-18T18:55:16+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 18 18:55:16 volumio go-librespot[4405]: time="2026-02-18T18:55:16+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 18 18:55:16 volumio go-librespot[4405]: time="2026-02-18T18:55:16+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 18 18:55:16 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 18 18:55:16 volumio go-librespot[4405]: time="2026-02-18T18:55:16+07:00" level=info msg="zeroconf server listening on port 36733" Feb 18 18:55:16 volumio go-librespot[4405]: time="2026-02-18T18:55:16+07:00" level=debug msg="obtained new client token: AAD6CgvIc7zSmIlYzCgM4xPn3KEQhmt28REJflceZTnY2h0Ht5U0+KF5JArcU22bd4H0PETnQC8b3K52NHUKGqsYGuuCUDGCN2bWdzcT5YfkJ5OyFRzYxxryaOr+ZukwTVkYJNJg/5qHCRHYCnoVM1QEq7dyvq689bNTDtrq9hml6sMrh7NxK51Edp2ltpygeEeiiy/GVM7QYjoIwItFBVTwAe2Y5J54q0D5Yb9a3Qp+78y2xPSaY43vdA==" Feb 18 18:55:16 volumio go-librespot[4405]: time="2026-02-18T18:55:16+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 18:55:17 volumio go-librespot[4405]: time="2026-02-18T18:55:17+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 18 18:55:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 18:55:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 18:55:20 volumio volumio[4426]: info: ------------------------------------------- Feb 18 18:55:20 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Feb 18 18:55:20 volumio volumio[4426]: info: ----- Volumio3 ---- Feb 18 18:55:20 volumio volumio[4426]: info: ------------------------------------------- Feb 18 18:55:20 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 18:55:20 volumio volumio[4426]: info: ----- System startup ---- Feb 18 18:55:20 volumio volumio[4426]: info: ------------------------------------------- Feb 18 18:55:20 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 18:55:20 volumio go-librespot[4447]: go-librespot daemon starting... Feb 18 18:55:20 volumio go-librespot[4448]: time="2026-02-18T18:55:20+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 18:55:20 volumio go-librespot[4448]: time="2026-02-18T18:55:20+07:00" level=debug msg="app state loaded" Feb 18 18:55:20 volumio go-librespot[4448]: time="2026-02-18T18:55:20+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 18:55:20 volumio go-librespot[4448]: time="2026-02-18T18:55:20+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 18:55:20 volumio go-librespot[4448]: time="2026-02-18T18:55:20+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 18:55:20 volumio go-librespot[4448]: time="2026-02-18T18:55:20+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 18:55:20 volumio go-librespot[4448]: time="2026-02-18T18:55:20+07:00" level=info msg="zeroconf server listening on port 34341" Feb 18 18:55:21 volumio go-librespot[4448]: time="2026-02-18T18:55:21+07:00" level=debug msg="obtained new client token: AAAiN9R7R1dVFYdVDbitV1O5rHoBgGIFd39rhFHSWIPDe/qIjG7PYu/o6JIsEVOE168dClUVtV4fev80riyb7FwUgSWJgyxmNOMCZI8xF48snDrzKUcFJzO62NBLSDAWU/3tH22taO2v24nj57RxY0pvJ59r9wFrsPvXIshfGEkpR/gIY2t1E71NDgOmM1i1ERxLH904Bn3fIN94vvr3B8mNulmjqZwLlmpDf7mNE3HtWPpov6h83vw=" Feb 18 18:55:21 volumio go-librespot[4448]: time="2026-02-18T18:55:21+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 18:55:21 volumio volumio-remote-updater[25144]: [2026-02-18 18:55:21] [connect] Successful connection Feb 18 18:55:21 volumio go-librespot[4448]: time="2026-02-18T18:55:21+07:00" level=debug msg="completed keyexchange" Feb 18 18:55:21 volumio go-librespot[4448]: time="2026-02-18T18:55:21+07:00" level=debug msg="completed challenge" Feb 18 18:55:21 volumio go-librespot[4448]: time="2026-02-18T18:55:21+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 18:55:21 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 18:55:21 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 18:55:21 volumio systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service... Feb 18 18:55:21 volumio volumio[4426]: info: MYVOLUMIO Environment detected Feb 18 18:55:21 volumio volumio[4426]: info: Plugin folders cleanup Feb 18 18:55:21 volumio volumio[4426]: info: Scanning into folder /volumio/app/plugins/ Feb 18 18:55:21 volumio volumio[4426]: info: Scanning category audio_interface Feb 18 18:55:21 volumio volumio[4426]: info: Scanning category miscellanea Feb 18 18:55:21 volumio volumio[4426]: info: Scanning category music_service Feb 18 18:55:21 volumio volumio[4426]: info: Scanning category plugins.json Feb 18 18:55:21 volumio volumio[4426]: info: Scanning category system_controller Feb 18 18:55:21 volumio volumio[4426]: info: Scanning category user_interface Feb 18 18:55:21 volumio volumio[4426]: info: Scanning into folder /data/plugins/ Feb 18 18:55:21 volumio volumio[4426]: info: Scanning category music_service Feb 18 18:55:21 volumio volumio[4426]: info: Plugin folders cleanup completed Feb 18 18:55:21 volumio volumio[4426]: info: ------------------------------------------- Feb 18 18:55:21 volumio volumio[4426]: info: ----- Core plugins startup ---- Feb 18 18:55:21 volumio volumio[4426]: info: ------------------------------------------- Feb 18 18:55:21 volumio volumio[4426]: info: Loading plugins from folder /volumio/app/plugins/ Feb 18 18:55:21 volumio volumio[4426]: info: Adding plugin upnp to MyMusic Plugins Feb 18 18:55:21 volumio volumio[4426]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 18 18:55:21 volumio volumio[4426]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 18 18:55:21 volumio volumio[4426]: info: Loading plugins from folder /data/plugins/ Feb 18 18:55:21 volumio volumio[4426]: info: Loading plugin "system"... Feb 18 18:55:21 volumio volumio[4426]: info: Loading plugin "appearance"... Feb 18 18:55:23 volumio systemd[1]: setdatetime-helper.service: Deactivated successfully. Feb 18 18:55:23 volumio systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service. Feb 18 18:55:23 volumio systemd[1]: setdatetime-helper.service: Consumed 1.933s CPU time. Feb 18 18:55:23 volumio volumio[4426]: info: Loading plugin "network"... Feb 18 18:55:24 volumio volumio[4426]: info: Refreshing Cached IP Addresses Feb 18 18:55:24 volumio sudo[4487]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 18 18:55:24 volumio sudo[4487]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 18:55:24 volumio volumio[4426]: info: Loading plugin "services"... Feb 18 18:55:24 volumio sudo[4489]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 18 18:55:24 volumio sudo[4489]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 18:55:24 volumio sudo[4487]: pam_unix(sudo:session): session closed for user root Feb 18 18:55:24 volumio volumio[4426]: info: Loading plugin "alsa_controller"... Feb 18 18:55:24 volumio sudo[4489]: pam_unix(sudo:session): session closed for user root Feb 18 18:55:24 volumio sudo[4501]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 18 18:55:24 volumio sudo[4501]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 18:55:24 volumio volumio[4426]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 18 18:55:24 volumio volumio[4426]: info: Loading plugin "wizard"... Feb 18 18:55:24 volumio volumio[4426]: info: Loading plugin "networkfs"... Feb 18 18:55:24 volumio volumio[4426]: info: Starting Udev Watcher for removable devices Feb 18 18:55:24 volumio volumio[4426]: info: Ignoring mount for partition: boot Feb 18 18:55:24 volumio volumio[4426]: info: Ignoring mount for partition: volumio Feb 18 18:55:24 volumio volumio[4426]: info: Ignoring mount for partition: volumio_data Feb 18 18:55:24 volumio volumio[4426]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 18 18:55:24 volumio volumio[4426]: info: Loading plugin "volumio_command_line_client"... Feb 18 18:55:24 volumio volumio[4426]: info: Loading plugin "upnp"... Feb 18 18:55:24 volumio volumio[4426]: info: [1771415724401] Starting Upmpd Daemon Feb 18 18:55:24 volumio volumio[4426]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 18 18:55:24 volumio volumio[4426]: info: Loading plugin "my_music"... Feb 18 18:55:24 volumio volumio[4426]: info: Loading plugin "mpd"... Feb 18 18:55:24 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Feb 18 18:55:24 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 18:55:24 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 18:55:24 volumio go-librespot[4520]: go-librespot daemon starting... Feb 18 18:55:24 volumio go-librespot[4521]: time="2026-02-18T18:55:24+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 18:55:24 volumio go-librespot[4521]: time="2026-02-18T18:55:24+07:00" level=debug msg="app state loaded" Feb 18 18:55:24 volumio go-librespot[4521]: time="2026-02-18T18:55:24+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 18:55:25 volumio volumio[4426]: info: Loading plugin "upnp_browser"... Feb 18 18:55:25 volumio go-librespot[4521]: time="2026-02-18T18:55:25+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 18:55:25 volumio go-librespot[4521]: time="2026-02-18T18:55:25+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 18:55:25 volumio go-librespot[4521]: time="2026-02-18T18:55:25+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 18:55:25 volumio go-librespot[4521]: time="2026-02-18T18:55:25+07:00" level=info msg="zeroconf server listening on port 41557" Feb 18 18:55:25 volumio go-librespot[4521]: time="2026-02-18T18:55:25+07:00" level=debug msg="obtained new client token: AACP6JM4QkLYKm97s1wbigES8X6JEzvXrJB/W1+pfSf3FJ9uxsHV4ROjxpbbB2TJTInvOYdQYm3EBQDCbxkvSQtQb9ioeFKkYhBjHF2yZgWdBNn/wpXmG5EpchFEnlv41+uHOsA5ij5N43ciCqFNJLFTfWRhkVyHf7BqyRRbqy4/8TsPdvpPx2u5e9bUteT7apqIryctJ0YpmcRhQeBcw8CKYCOEt1k0ebQd7Oi9HDnTbKjQqPlZuVGMvg==" Feb 18 18:55:25 volumio go-librespot[4521]: time="2026-02-18T18:55:25+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 18:55:25 volumio go-librespot[4521]: time="2026-02-18T18:55:25+07:00" level=debug msg="completed keyexchange" Feb 18 18:55:25 volumio go-librespot[4521]: time="2026-02-18T18:55:25+07:00" level=debug msg="completed challenge" Feb 18 18:55:25 volumio go-librespot[4521]: time="2026-02-18T18:55:25+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 18:55:25 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 18:55:25 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 18:55:26 volumio sudo[4501]: pam_unix(sudo:session): session closed for user root Feb 18 18:55:28 volumio volumio[4426]: info: Starting UPNP Browser Feb 18 18:55:28 volumio volumio[4426]: info: Loading plugin "alarm-clock"... Feb 18 18:55:28 volumio volumio[4426]: info: Loading plugin "airplay_emulation"... Feb 18 18:55:28 volumio volumio[4426]: info: Starting Shairport Sync Feb 18 18:55:28 volumio volumio[4426]: info: Loading plugin "last_100"... Feb 18 18:55:28 volumio volumio[4426]: info: Loading plugin "webradio"... Feb 18 18:55:28 volumio volumio[4426]: info: Loading plugin "i2s_dacs"... Feb 18 18:55:28 volumio volumio[4426]: info: Loading plugin "volumiodiscovery"... Feb 18 18:55:28 volumio volumio[4426]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 18 18:55:28 volumio volumio[4426]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 18:55:28 volumio node[4426]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 18 18:55:28 volumio volumio[4426]: *** WARNING *** For more information see Feb 18 18:55:28 volumio volumio[4426]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 18 18:55:28 volumio volumio[4426]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 18:55:28 volumio volumio[4426]: *** WARNING *** For more information see Feb 18 18:55:28 volumio node[4426]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 18:55:28 volumio node[4426]: *** WARNING *** For more information see Feb 18 18:55:28 volumio node[4426]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 18 18:55:28 volumio node[4426]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 18 18:55:28 volumio node[4426]: *** WARNING *** For more information see Feb 18 18:55:28 volumio volumio[4426]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 18 18:55:28 volumio volumio[4426]: info: Discovery: Started advertising with name: Volumio Feb 18 18:55:28 volumio volumio[4426]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 18 18:55:28 volumio volumio[4426]: info: Loading plugin "spop"... Feb 18 18:55:28 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15. Feb 18 18:55:28 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 18:55:29 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 18:55:29 volumio go-librespot[4530]: go-librespot daemon starting... Feb 18 18:55:29 volumio go-librespot[4531]: time="2026-02-18T18:55:29+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 18:55:29 volumio go-librespot[4531]: time="2026-02-18T18:55:29+07:00" level=debug msg="app state loaded" Feb 18 18:55:29 volumio go-librespot[4531]: time="2026-02-18T18:55:29+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 18:55:29 volumio go-librespot[4531]: time="2026-02-18T18:55:29+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 18:55:29 volumio go-librespot[4531]: time="2026-02-18T18:55:29+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 18:55:29 volumio go-librespot[4531]: time="2026-02-18T18:55:29+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 18:55:29 volumio go-librespot[4531]: time="2026-02-18T18:55:29+07:00" level=info msg="zeroconf server listening on port 43339" Feb 18 18:55:29 volumio go-librespot[4531]: time="2026-02-18T18:55:29+07:00" level=debug msg="obtained new client token: AACw2OuMBxM2gd2tIFDaic4DpSpaaG3vL35J+8ZYbwlWtp9VcUpSrrJzWCrvTezaVpMN61FIquhSSKm5bV8jhpikQPLZPGtpeTRZlvgsbN2ad+C7o8BrWxJ7wl7unHELyhl1pTwcWetCCPn8fklJ9iOegEHY5aTOHTzyWklatEJRzjOegUUiaX6dWPeKrpflv7w95TsLjp3RTLdQqz7cWWz3b+3Bv7heIVxJl24kWHj2+K/7GTLpuRVmVg==" Feb 18 18:55:29 volumio go-librespot[4531]: time="2026-02-18T18:55:29+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 18:55:30 volumio go-librespot[4531]: time="2026-02-18T18:55:30+07:00" level=debug msg="completed keyexchange" Feb 18 18:55:30 volumio go-librespot[4531]: time="2026-02-18T18:55:30+07:00" level=debug msg="completed challenge" Feb 18 18:55:30 volumio go-librespot[4531]: time="2026-02-18T18:55:30+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 18:55:30 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 18:55:30 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 18:55:30 volumio volumio[4426]: info: Loading plugin "ytcr"... Feb 18 18:55:33 volumio volumio[4426]: info: Loading plugin "ytmusic"... Feb 18 18:55:33 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Feb 18 18:55:33 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 18:55:33 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 18:55:33 volumio go-librespot[4541]: go-librespot daemon starting... Feb 18 18:55:33 volumio go-librespot[4542]: time="2026-02-18T18:55:33+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 18:55:33 volumio go-librespot[4542]: time="2026-02-18T18:55:33+07:00" level=debug msg="app state loaded" Feb 18 18:55:33 volumio go-librespot[4542]: time="2026-02-18T18:55:33+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 18:55:33 volumio volumio-remote-updater[25144]: [2026-02-18 18:55:33] [connect] Successful connection Feb 18 18:55:33 volumio go-librespot[4542]: time="2026-02-18T18:55:33+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 18:55:33 volumio go-librespot[4542]: time="2026-02-18T18:55:33+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 18:55:33 volumio go-librespot[4542]: time="2026-02-18T18:55:33+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 18:55:33 volumio go-librespot[4542]: time="2026-02-18T18:55:33+07:00" level=info msg="zeroconf server listening on port 37625" Feb 18 18:55:34 volumio go-librespot[4542]: time="2026-02-18T18:55:34+07:00" level=debug msg="obtained new client token: AABroFSMO4+hkIRTv2so0nPVbsZxGr2clXB/vSPK1bQdrZYcoFwVdiUXkCOcFuLd6k8EUS3uzGLNuYKMchkgFnnXA0SfJhTX3pTOUGx+hf75wHKC6nDD8LKF2WpalhXRC159wKyvKHuU7Ru4Oy+4CQey7KhiqLkpPl7yvriugSG8fH0s2zvAAMwylvuxwvbgknQw4gucDiUC8Bj5UQhZgzXq/fUzZQ7A8aOfSBHIUK9F6dJxIv04InM=" Feb 18 18:55:34 volumio go-librespot[4542]: time="2026-02-18T18:55:34+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 18:55:34 volumio volumio[4426]: info: Loading plugin "outputs"... Feb 18 18:55:34 volumio volumio[4426]: info: Loading plugin "albumart"... Feb 18 18:55:34 volumio volumio[4426]: info: Plugin example_plugin is not enabled Feb 18 18:55:34 volumio volumio[4426]: info: Loading plugin "inputs"... Feb 18 18:55:34 volumio volumio[4426]: info: Loading plugin "updater_comm"... Feb 18 18:55:34 volumio go-librespot[4542]: time="2026-02-18T18:55:34+07:00" level=debug msg="completed keyexchange" Feb 18 18:55:34 volumio go-librespot[4542]: time="2026-02-18T18:55:34+07:00" level=debug msg="completed challenge" Feb 18 18:55:34 volumio go-librespot[4542]: time="2026-02-18T18:55:34+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 18:55:34 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 18:55:34 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 18:55:34 volumio volumio[4426]: info: Plugin mpdemulation is not enabled Feb 18 18:55:34 volumio volumio[4426]: info: Loading plugin "rest_api"... Feb 18 18:55:34 volumio volumio[4426]: info: Loading plugin "websocket"... Feb 18 18:55:34 volumio volumio[4426]: info: Starting Socket.io Server version 1.7.4 Feb 18 18:55:34 volumio volumio[4426]: info: Loading plugin "RoonBridge"... Feb 18 18:55:35 volumio volumio[4426]: info: Applying required configuration parameters for plugin RoonBridge Feb 18 18:55:35 volumio volumio[4426]: info: Loading i18n strings for locale en Feb 18 18:55:35 volumio volumio[4426]: Updating browse sources language Feb 18 18:55:35 volumio volumio[4426]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 18:55:35 volumio volumio[4563]: Forking 3 albumart workers Feb 18 18:55:35 volumio volumio[4426]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 18 18:55:35 volumio volumio[4426]: info: CoreCommandRouter::initPlayerControls Feb 18 18:55:35 volumio volumio[4426]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 18:55:35 volumio volumio[4426]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 18:55:35 volumio volumio[4426]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 18:55:35 volumio volumio[4426]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 18:55:35 volumio volumio[4426]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 18:55:35 volumio volumio[4426]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 18:55:35 volumio volumio[4426]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 18:55:35 volumio volumio[4426]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 18:55:35 volumio volumio[4426]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 18 18:55:35 volumio volumio[4426]: Express server listening on port 3000 Feb 18 18:55:35 volumio volumio[4426]: [Metrics] WebUI: 16s 199.92ms Feb 18 18:55:35 volumio volumio[4426]: info: CoreStateMachine::resetVolumioState Feb 18 18:55:35 volumio volumio[4426]: info: CoreStateMachine::getcurrentVolume Feb 18 18:55:35 volumio volumio[4426]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 18:55:35 volumio sudo[4607]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 18 18:55:35 volumio sudo[4607]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 18:55:35 volumio sudo[4605]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 18 18:55:35 volumio sudo[4605]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 18:55:35 volumio sudo[4607]: pam_unix(sudo:session): session closed for user root Feb 18 18:55:35 volumio sudo[4605]: pam_unix(sudo:session): session closed for user root Feb 18 18:55:35 volumio volumio[4426]: info: Volumio Network Manager: Network status updated: 1 Feb 18 18:55:36 volumio volumio[4426]: info: VolumeController:: Volume=100 Mute =false Feb 18 18:55:36 volumio volumio[4426]: info: CoreStateMachine::pushState Feb 18 18:55:36 volumio volumio[4426]: info: CorePlayQueue::getTrack 0 Feb 18 18:55:36 volumio volumio[4426]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 18 18:55:36 volumio volumio[4426]: info: CoreCommandRouter::volumioPushState Feb 18 18:55:36 volumio volumio[4426]: info: CoreStateMachine::updateTrackBlock Feb 18 18:55:36 volumio volumio[4426]: info: CorePlayQueue::getTrackBlock Feb 18 18:55:36 volumio volumio[4426]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 18:55:36 volumio volumio-remote-updater[25144]: [2026-02-18 18:55:36] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1771415733 101 Feb 18 18:55:36 volumio volumio[4426]: 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 Feb 18 18:55:36 volumio volumio[4426]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 18:55:36 volumio volumio[4426]: info: Reloading queue from file Feb 18 18:55:36 volumio volumio[4426]: info: CoreStateMachine::setRepeat null single undefined Feb 18 18:55:36 volumio volumio[4426]: info: CoreStateMachine::pushState Feb 18 18:55:36 volumio volumio[4426]: info: CorePlayQueue::getTrack 0 Feb 18 18:55:36 volumio volumio[4426]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 18 18:55:36 volumio volumio[4426]: info: CoreCommandRouter::volumioPushState Feb 18 18:55:36 volumio volumio[4426]: info: CoreStateMachine::setRandom null Feb 18 18:55:36 volumio volumio[4426]: info: CoreStateMachine::pushState Feb 18 18:55:36 volumio volumio[4426]: info: CorePlayQueue::getTrack 0 Feb 18 18:55:36 volumio volumio[4426]: info: CoreCommandRouter::volumioPushState Feb 18 18:55:36 volumio volumio[4426]: info: Setting Device type: Raspberry PI Feb 18 18:55:36 volumio volumio[4426]: info: Completed loading Core Plugins Feb 18 18:55:36 volumio volumio[4426]: info: Preparing to generate the ALSA configuration file Feb 18 18:55:36 volumio volumio[4426]: info: VolumeController:: Volume=100 Mute =false Feb 18 18:55:36 volumio volumio[4426]: info: CoreStateMachine::pushState Feb 18 18:55:36 volumio volumio[4426]: info: CorePlayQueue::getTrack 0 Feb 18 18:55:36 volumio volumio[4426]: info: CoreCommandRouter::volumioPushState Feb 18 18:55:36 volumio volumio[4426]: info: Asound.conf file unchanged, so no further update is needed Feb 18 18:55:36 volumio volumio[4426]: info: Output device has changed, restarting MPD Feb 18 18:55:36 volumio volumio[4426]: info: Output device has changed, restarting Shairport Sync Feb 18 18:55:36 volumio volumio[4426]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 18:55:36 volumio volumio[4426]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 18:55:36 volumio sudo[4624]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 18 18:55:36 volumio sudo[4624]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 18:55:36 volumio sudo[4626]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 18 18:55:36 volumio sudo[4626]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 18:55:36 volumio sudo[4628]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 18 18:55:36 volumio sudo[4628]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 18:55:36 volumio volumio[4426]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 18 18:55:36 volumio volumio[4426]: info: ___________ START PLUGINS ___________ Feb 18 18:55:36 volumio sudo[4626]: pam_unix(sudo:session): session closed for user root Feb 18 18:55:36 volumio volumio[4426]: info: ControllerMpd::onStart: Initializing MPD Feb 18 18:55:36 volumio volumio[4426]: info: Creating MPD Configuration file Feb 18 18:55:36 volumio sudo[4624]: pam_unix(sudo:session): session closed for user root Feb 18 18:55:36 volumio volumio[4426]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 18 18:55:36 volumio volumio[4426]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 18:55:36 volumio volumio[4426]: info: [1771415736911] CoreMusicLibrary::Adding element Media Servers Feb 18 18:55:36 volumio volumio[4426]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 18:55:36 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 18 18:55:36 volumio volumio[4426]: info: UPNP Browser: Client initialized successfully Feb 18 18:55:37 volumio sudo[4637]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 18 18:55:37 volumio sudo[4637]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 18:55:37 volumio sudo[4637]: pam_unix(sudo:session): session closed for user root Feb 18 18:55:37 volumio sudo[4639]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 18 18:55:37 volumio sudo[4639]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 18:55:37 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 18 18:55:37 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 18 18:55:37 volumio systemd[1]: mpd.service: Consumed 7.213s CPU time. Feb 18 18:55:37 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 18 18:55:37 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 18 18:55:37 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 18 18:55:37 volumio volumio[4426]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 18:55:37 volumio volumio[4426]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 18:55:37 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 18 18:55:37 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 18 18:55:37 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 18 18:55:37 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 18 18:55:37 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 18 18:55:37 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 18 18:55:37 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 18 18:55:37 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 18 18:55:37 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 18 18:55:37 volumio volumio[4426]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 18 18:55:37 volumio volumio[4426]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 18:55:37 volumio volumio[4426]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 18:55:37 volumio volumio[4426]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 18 18:55:37 volumio volumio[4426]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 18:55:37 volumio volumio[4426]: info: [1771415737371] CoreMusicLibrary::Adding element Last_100 Feb 18 18:55:37 volumio volumio[4426]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 18:55:37 volumio volumio[4426]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 18:55:37 volumio volumio[4426]: info: [1771415737396] CoreMusicLibrary::Adding element Webradio Feb 18 18:55:37 volumio volumio[4426]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 18:55:37 volumio volumio[4426]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 18 18:55:37 volumio volumio[4426]: info: Initializing BBC Radios Feb 18 18:55:37 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17. Feb 18 18:55:37 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 18:55:37 volumio volumio[4426]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 18 18:55:37 volumio volumio[4426]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 18:55:37 volumio volumio[4426]: info: Creating Spotify config file Feb 18 18:55:37 volumio volumio[4426]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 18:55:37 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 18:55:37 volumio go-librespot[4667]: go-librespot daemon starting... Feb 18 18:55:37 volumio go-librespot[4668]: time="2026-02-18T18:55:37+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 18:55:37 volumio sudo[4649]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 18 18:55:37 volumio sudo[4649]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 18 18:55:37 volumio sudo[4649]: pam_unix(sudo:session): session closed for user root Feb 18 18:55:38 volumio go-librespot[4668]: time="2026-02-18T18:55:38+07:00" level=info msg="zeroconf server listening on port 44691" Feb 18 18:55:38 volumio volumio[4573]: Starting albumart workers Feb 18 18:55:38 volumio volumio[4574]: Starting albumart workers Feb 18 18:55:39 volumio volumio[4575]: Starting albumart workers Feb 18 18:55:39 volumio volumio[4426]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 18:55:39 volumio volumio[4426]: info: [1771415739289] CoreMusicLibrary::Adding element YouTube Music Feb 18 18:55:39 volumio volumio[4426]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 18:55:39 volumio volumio[4426]: Cannot find translation for source YouTube Music Feb 18 18:55:39 volumio volumio[4426]: info: Volumio Calling Home Feb 18 18:55:39 volumio sudo[4679]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 18 18:55:39 volumio sudo[4679]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 18:55:39 volumio sudo[4679]: pam_unix(sudo:session): session closed for user root Feb 18 18:55:40 volumio volumio[4426]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 18 18:55:40 volumio volumio[4426]: info: Discovery: Found device Volumio Feb 18 18:55:40 volumio volumio[4426]: info: CoreCommandRouter::volumioGetState Feb 18 18:55:40 volumio volumio[4426]: info: CorePlayQueue::getTrack 0 Feb 18 18:55:40 volumio volumio[4426]: info: MPD Permissions set Feb 18 18:55:40 volumio volumio[4426]: info: MPD Permissions set Feb 18 18:55:40 volumio volumio[4426]: info: Upmpdcli Daemon Started Feb 18 18:55:40 volumio volumio[4426]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 18 18:55:40 volumio volumio[4426]: info: Discovery: Found device Volumio Feb 18 18:55:40 volumio volumio[4426]: info: CoreCommandRouter::volumioGetState Feb 18 18:55:40 volumio volumio[4426]: info: CorePlayQueue::getTrack 0 Feb 18 18:55:40 volumio volumio[4426]: info: Spotify config file written Feb 18 18:55:40 volumio volumio[4426]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Feb 18 18:55:40 volumio sudo[4685]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 18 18:55:40 volumio sudo[4685]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 18:55:40 volumio volumio[4426]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 18:55:40 volumio volumio[4426]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 18:55:40 volumio volumio[4426]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 18:55:40 volumio volumio[4426]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 18:55:40 volumio volumio[4426]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 18:55:40 volumio volumio[4426]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 18:55:40 volumio volumio[4426]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 18:55:40 volumio volumio[4426]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 18:55:40 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 18 18:55:40 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 18 18:55:40 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 18:55:40 volumio volumio[4426]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 18:55:40 volumio volumio[4426]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 18:55:40 volumio volumio[4426]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 18:55:40 volumio volumio[4426]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 18:55:40 volumio volumio[4426]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 18:55:40 volumio volumio[4426]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 18:55:40 volumio volumio[4426]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 18:55:40 volumio volumio[4426]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 18:55:40 volumio volumio[4426]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 18:55:40 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 18:55:40 volumio go-librespot[4698]: go-librespot daemon starting... Feb 18 18:55:40 volumio volumio[4426]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 18:55:40 volumio sudo[4685]: pam_unix(sudo:session): session closed for user root Feb 18 18:55:40 volumio go-librespot[4700]: time="2026-02-18T18:55:40+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 18:55:40 volumio go-librespot[4700]: time="2026-02-18T18:55:40+07:00" level=debug msg="app state loaded" Feb 18 18:55:40 volumio go-librespot[4700]: time="2026-02-18T18:55:40+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 18:55:40 volumio volumio[4426]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 18:55:40 volumio volumio[4426]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 18 18:55:40 volumio volumio[4426]: info: No need to fix Spotify hosts Feb 18 18:55:41 volumio go-librespot[4700]: time="2026-02-18T18:55:41+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 18:55:41 volumio go-librespot[4700]: time="2026-02-18T18:55:41+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 18:55:41 volumio go-librespot[4700]: time="2026-02-18T18:55:41+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 18:55:41 volumio go-librespot[4700]: time="2026-02-18T18:55:41+07:00" level=info msg="zeroconf server listening on port 37339" Feb 18 18:55:41 volumio go-librespot[4700]: time="2026-02-18T18:55:41+07:00" level=debug msg="obtained new client token: AABGHJ1sUIYDxSWZMOcH/9sCIAPOKW0dBUok+9bjKHe63iVRYr1bXFlkjGPZYhqEhBnJU1eA47G1farTr8uqguJfmpDppvDIO6+QHtnHfPcFj4TEmIptCexQi9vxlXigLuSHQS4wczmzVB0a8ycTS/S5ygJCCR37j9VI5gj9b5Wdj8IQ2BSR8gfJ6HQMpXEUvTkC+4t+s76a/PAxjpOgeCDxDdQbXiuUt15WsMl8zE8jEl+dgcgMywRVvg==" Feb 18 18:55:41 volumio volumio[4426]: info: Volumio called home Feb 18 18:55:41 volumio volumio[4426]: info: Starting Shairport Sync Feb 18 18:55:41 volumio volumio[4426]: info: Starting Shairport Sync Feb 18 18:55:41 volumio go-librespot[4700]: time="2026-02-18T18:55:41+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 18:55:41 volumio volumio[4426]: info: Starting Shairport Sync Feb 18 18:55:41 volumio sudo[4724]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 18:55:41 volumio sudo[4724]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 18:55:41 volumio sudo[4726]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 18:55:41 volumio sudo[4726]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 18:55:41 volumio go-librespot[4700]: time="2026-02-18T18:55:41+07:00" level=debug msg="completed keyexchange" Feb 18 18:55:41 volumio go-librespot[4700]: time="2026-02-18T18:55:41+07:00" level=debug msg="completed challenge" Feb 18 18:55:41 volumio sudo[4728]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 18 18:55:41 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 18 18:55:41 volumio sudo[4728]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 18:55:41 volumio go-librespot[4700]: time="2026-02-18T18:55:41+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 18:55:41 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 18 18:55:41 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 18:55:41 volumio systemd[1]: shairport-sync.service: Consumed 2.300s CPU time. Feb 18 18:55:41 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 18:55:41 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 18:55:42 volumio volumio[4426]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 18 18:55:42 volumio volumio[4426]: SPOTIFY: BQDEIyDJeKzd7aTlPCqiXudHCyeIe_W6iMFnUU_EBACP-0L3D8YbFPXGFWX_LyU5tIpG8jS-pkZy0Rj6qHK_i6TYVWqY_zTDsxLZ9zQ7tuTBtHAF3p_6wz1SNNR12u7MrD0R-jr6Dc7cdxd-yOxWQFC86QUVrfZ_RIZ0aZGqTKqqibW-QdKeGeboUiqsLe9ezqEWN1G81JsPy4G3df5yNtDZClXg3BSB7otmDuYNF_M5q0y6ssAfdyfvy9cPapFiVc7oiqhcInB6S8qwynKdZauFxaie9szOUdWF6C0fvA_2acRqvm9TWLNH Feb 18 18:55:42 volumio volumio[4426]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 18 18:55:42 volumio volumio[4426]: info: New Spotify access token = BQDEIyDJeKzd7aTlPCqiXudHCyeIe_W6iMFnUU_EBACP-0L3D8YbFPXGFWX_LyU5tIpG8jS-pkZy0Rj6qHK_i6TYVWqY_zTDsxLZ9zQ7tuTBtHAF3p_6wz1SNNR12u7MrD0R-jr6Dc7cdxd-yOxWQFC86QUVrfZ_RIZ0aZGqTKqqibW-QdKeGeboUiqsLe9ezqEWN1G81JsPy4G3df5yNtDZClXg3BSB7otmDuYNF_M5q0y6ssAfdyfvy9cPapFiVc7oiqhcInB6S8qwynKdZauFxaie9szOUdWF6C0fvA_2acRqvm9TWLNH Feb 18 18:55:42 volumio volumio[4426]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 18 18:55:42 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 18 18:55:42 volumio sudo[4726]: pam_unix(sudo:session): session closed for user root Feb 18 18:55:42 volumio sudo[4724]: pam_unix(sudo:session): session closed for user root Feb 18 18:55:42 volumio sudo[4728]: pam_unix(sudo:session): session closed for user root Feb 18 18:55:42 volumio volumio[4426]: info: Shairport-Sync Started Feb 18 18:55:42 volumio volumio[4426]: Error adding Membership: Error: addMembership EINVAL Feb 18 18:55:42 volumio volumio[4426]: info: Shairport-Sync Started Feb 18 18:55:42 volumio volumio[4426]: info: Shairport-Sync Started Feb 18 18:55:42 volumio volumio[4426]: info: CoreCommandRouter::volumioGetState Feb 18 18:55:42 volumio volumio[4426]: info: CorePlayQueue::getTrack 0 Feb 18 18:55:42 volumio volumio[4426]: SPOTIFY: User informations: {"country":"PK","display_name":"215mmgea6kss3jxeqsqdquvji","email":"linh.ngotran@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/215mmgea6kss3jxeqsqdquvji"},"followers":{"href":null,"total":1},"href":"https://api.spotify.com/v1/users/215mmgea6kss3jxeqsqdquvji","id":"215mmgea6kss3jxeqsqdquvji","images":[],"product":"premium","type":"user","uri":"spotify:user:215mmgea6kss3jxeqsqdquvji"} Feb 18 18:55:42 volumio volumio[4426]: info: Spotify Successfully logged in Feb 18 18:55:42 volumio volumio[4426]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 18 18:55:42 volumio volumio[4426]: info: [1771415742745] CoreMusicLibrary::Adding element Spotify Feb 18 18:55:42 volumio volumio[4426]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 18 18:55:42 volumio volumio[4426]: Cannot find translation for source YouTube Music Feb 18 18:55:42 volumio volumio[4426]: Cannot find translation for source Spotify Feb 18 18:55:43 volumio volumio[4426]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 18 18:55:43 volumio volumio[4426]: info: CoreCommandRouter::volumioRetrievevolume Feb 18 18:55:43 volumio volumio[4426]: info: VolumeController:: Volume=100 Mute =false Feb 18 18:55:43 volumio volumio[4426]: info: CoreCommandRouter::volumioGetState Feb 18 18:55:43 volumio volumio[4426]: info: CorePlayQueue::getTrack 0 Feb 18 18:55:43 volumio volumio[4426]: info: CoreStateMachine::pushState Feb 18 18:55:43 volumio volumio[4426]: info: CorePlayQueue::getTrack 0 Feb 18 18:55:43 volumio volumio[4426]: info: CoreCommandRouter::volumioPushState Feb 18 18:55:44 volumio volumio[4426]: info: go-librespot daemon successfully initialized Feb 18 18:55:44 volumio mpd[4675]: 2026-02-18T18:55:44 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 18 18:55:44 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 18 18:55:44 volumio sudo[4639]: pam_unix(sudo:session): session closed for user root Feb 18 18:55:44 volumio sudo[4628]: pam_unix(sudo:session): session closed for user root Feb 18 18:55:45 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 18 18:55:45 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 18:55:45 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 18:55:45 volumio go-librespot[4770]: go-librespot daemon starting... Feb 18 18:55:45 volumio go-librespot[4771]: time="2026-02-18T18:55:45+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 18:55:45 volumio go-librespot[4771]: time="2026-02-18T18:55:45+07:00" level=debug msg="app state loaded" Feb 18 18:55:45 volumio go-librespot[4771]: time="2026-02-18T18:55:45+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 18:55:45 volumio volumio[4426]: error: MPD error: The expression evaluated to a falsy value: Feb 18 18:55:45 volumio volumio[4426]: assert.ok(self.idling) Feb 18 18:55:45 volumio volumio[4426]: error: The expression evaluated to a falsy value: Feb 18 18:55:45 volumio volumio[4426]: assert.ok(self.idling) Feb 18 18:55:45 volumio volumio[4426]: error: updateQueue error: null Feb 18 18:55:45 volumio volumio[4426]: info: MPD running with PID4675 Feb 18 18:55:45 volumio volumio[4426]: ,establishing connection Feb 18 18:55:45 volumio volumio[4426]: info: Completed starting Core Plugins Feb 18 18:55:45 volumio volumio[4426]: info: ------------------------------------------- Feb 18 18:55:45 volumio volumio[4426]: info: ----- MyVolumio plugins startup ---- Feb 18 18:55:45 volumio volumio[4426]: info: ------------------------------------------- Feb 18 18:55:45 volumio volumio[4426]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 18 18:55:45 volumio volumio[4426]: error: updateQueue error: null Feb 18 18:55:45 volumio go-librespot[4771]: time="2026-02-18T18:55:45+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 18:55:45 volumio go-librespot[4771]: time="2026-02-18T18:55:45+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 18:55:45 volumio go-librespot[4771]: time="2026-02-18T18:55:45+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 18:55:45 volumio go-librespot[4771]: time="2026-02-18T18:55:45+07:00" level=info msg="zeroconf server listening on port 42033" Feb 18 18:55:45 volumio go-librespot[4771]: time="2026-02-18T18:55:45+07:00" level=debug msg="obtained new client token: AADlZqR0UBNcxvgEDfBgKOEeYZQEs76RF4bnhG1RG613q3bpcLY4gyhIHsR8m4qVqBV+Z13LuH2Sco8gkCSodkys1djBR/IhTt8W9TK+tuKO4mAFdDMZn/2Xi7jpxhSyS8lshaMkEcbR5qLt/bn/Wfhr2pTM2vJzsGbAyCfK8rJCiK/lIA1Shh6p7v45bmLvTxr34EOs8JpVb+l0ytLs5L0aAuvqKBqAn10Bfl7uT8/wQHU+sOdIw9Rndg==" Feb 18 18:55:45 volumio go-librespot[4771]: time="2026-02-18T18:55:45+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 18:55:46 volumio go-librespot[4771]: time="2026-02-18T18:55:46+07:00" level=debug msg="completed keyexchange" Feb 18 18:55:46 volumio go-librespot[4771]: time="2026-02-18T18:55:46+07:00" level=debug msg="completed challenge" Feb 18 18:55:46 volumio go-librespot[4771]: time="2026-02-18T18:55:46+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 18:55:46 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 18:55:46 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 18:55:47 volumio volumio[4426]: info: Initializing connection to go-librespot Websocket Feb 18 18:55:47 volumio volumio[4426]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 18:55:49 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 18 18:55:49 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 18:55:49 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 18:55:49 volumio go-librespot[4779]: go-librespot daemon starting... Feb 18 18:55:49 volumio go-librespot[4780]: time="2026-02-18T18:55:49+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 18:55:49 volumio go-librespot[4780]: time="2026-02-18T18:55:49+07:00" level=debug msg="app state loaded" Feb 18 18:55:49 volumio go-librespot[4780]: time="2026-02-18T18:55:49+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 18:55:49 volumio go-librespot[4780]: time="2026-02-18T18:55:49+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 18 18:55:49 volumio go-librespot[4780]: time="2026-02-18T18:55:49+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 18 18:55:49 volumio go-librespot[4780]: time="2026-02-18T18:55:49+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 18 18:55:49 volumio go-librespot[4780]: time="2026-02-18T18:55:49+07:00" level=info msg="zeroconf server listening on port 40161" Feb 18 18:55:50 volumio volumio[4426]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 18 18:55:50 volumio go-librespot[4780]: time="2026-02-18T18:55:50+07:00" level=debug msg="obtained new client token: AAD7yT8yTGwviJhTG1kuTgvq5uvGFoIxYsfxM+ka2Cv6nQajRoprt3hFcVqiO1Xopxr0ynKmSVVnHug/zXNxkTXinhzuDKQeyC+aclzLpiMhZWTH9u/z1ToPqhi2qdeDn1cBBkR/o9h9zYOMdBzYMDKc8/K01LmOpL6ceMbs17Htz8uvUtO88/8x7kV+bdGOO8ThZ24DvA1/ULXAX2Oc0RsmapbCejpJIs75Y/xGrSjaWPHZSxPSvBU=" Feb 18 18:55:50 volumio go-librespot[4780]: time="2026-02-18T18:55:50+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 18:55:50 volumio go-librespot[4780]: time="2026-02-18T18:55:50+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 18 18:55:50 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 18:55:50 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 18:55:50 volumio volumio[4426]: info: Initializing connection to go-librespot Websocket Feb 18 18:55:50 volumio volumio[4426]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 18:55:53 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 18 18:55:53 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 18:55:53 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 18:55:53 volumio go-librespot[4788]: go-librespot daemon starting... Feb 18 18:55:53 volumio go-librespot[4789]: time="2026-02-18T18:55:53+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 18:55:53 volumio go-librespot[4789]: time="2026-02-18T18:55:53+07:00" level=debug msg="app state loaded" Feb 18 18:55:53 volumio go-librespot[4789]: time="2026-02-18T18:55:53+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 18:55:53 volumio volumio[4426]: info: Initializing connection to go-librespot Websocket Feb 18 18:55:53 volumio go-librespot[4789]: time="2026-02-18T18:55:53+07:00" level=debug msg="new websocket client" Feb 18 18:55:53 volumio volumio[4426]: info: Connection to go-librespot Websocket established Feb 18 18:55:54 volumio volumio[4426]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 18 18:55:54 volumio volumio[4426]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 18 18:55:54 volumio volumio[4426]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 18 18:55:54 volumio volumio[4426]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 18 18:55:54 volumio volumio[4426]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 18 18:55:54 volumio volumio[4426]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 18 18:55:54 volumio volumio[4426]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 18 18:55:54 volumio volumio[4426]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 18 18:55:54 volumio volumio[4426]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 18 18:55:54 volumio volumio[4426]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 18 18:55:54 volumio volumio[4426]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 18 18:55:54 volumio volumio[4426]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 18 18:55:54 volumio volumio[4426]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 18 18:55:54 volumio volumio[4426]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 18 18:55:54 volumio volumio[4426]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 18 18:55:54 volumio volumio[4426]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 18 18:55:54 volumio volumio[4426]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 18 18:55:54 volumio volumio[4426]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 18 18:55:54 volumio volumio[4426]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 18 18:55:54 volumio volumio[4426]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 18 18:55:54 volumio volumio[4426]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 18 18:55:54 volumio volumio[4426]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 18 18:55:54 volumio volumio[4426]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 18 18:55:54 volumio volumio[4426]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 18 18:55:54 volumio volumio[4426]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 18 18:55:54 volumio volumio[4426]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 18 18:55:54 volumio volumio[4426]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 18 18:55:54 volumio volumio[4426]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 18 18:55:54 volumio volumio[4426]: info: Adding plugin bluetooth to MyMusic Plugins Feb 18 18:55:54 volumio volumio[4426]: info: Adding plugin multiroom to MyMusic Plugins Feb 18 18:55:54 volumio volumio[4426]: info: Adding plugin metavolumio to MyMusic Plugins Feb 18 18:55:54 volumio volumio[4426]: info: Adding plugin cd_controller to MyMusic Plugins Feb 18 18:55:54 volumio volumio[4426]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 18 18:55:54 volumio volumio[4426]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 18 18:55:54 volumio volumio[4426]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 18 18:55:54 volumio volumio[4426]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 18 18:55:54 volumio go-librespot[4789]: time="2026-02-18T18:55:54+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 18:55:54 volumio go-librespot[4789]: time="2026-02-18T18:55:54+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 18:55:54 volumio go-librespot[4789]: time="2026-02-18T18:55:54+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 18:55:54 volumio go-librespot[4789]: time="2026-02-18T18:55:54+07:00" level=info msg="zeroconf server listening on port 34831" Feb 18 18:55:54 volumio go-librespot[4789]: time="2026-02-18T18:55:54+07:00" level=debug msg="obtained new client token: AADvmBCuYTGGj0oCi9uxBhw+jzo7CXuGAFPLAXcTDzEgaOtkyOVMJVnaD+mVHGcGlgMUmUa4nxvasoNcXR3BGHex8Voi+H/B2R4pc4jK5zGicTVI8L/vUebvn/BmnC5JYjTRQUhf9VZG2mHGg+P4zyJTcsh3VWwdd4UMFzo+HZNQydGgIEBCGK+OpWhs00sAyQrdnOT076qM+XnanE5/mV7DBmddvo6iL1nt7tt9sTmsIMJHIR1VYtFhEQ==" Feb 18 18:55:54 volumio go-librespot[4789]: time="2026-02-18T18:55:54+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 18:55:55 volumio go-librespot[4789]: time="2026-02-18T18:55:55+07:00" level=debug msg="completed keyexchange" Feb 18 18:55:55 volumio go-librespot[4789]: time="2026-02-18T18:55:55+07:00" level=debug msg="completed challenge" Feb 18 18:55:55 volumio go-librespot[4789]: time="2026-02-18T18:55:55+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 18 18:55:55 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 18 18:55:55 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 18 18:55:55 volumio volumio[4426]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 18 18:55:55 volumio volumio[4426]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 18 18:55:55 volumio volumio[4426]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 18:55:55 volumio volumio[4426]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 18 18:55:55 volumio volumio[4426]: info: Starting MyVolumio Remote Streaming Endpoints Feb 18 18:55:55 volumio volumio[4426]: info: MyVolumio login type: Token Feb 18 18:55:56 volumio volumio[4426]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 18 18:55:56 volumio volumio[4426]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 18 18:55:57 volumio volumio[4426]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 18 18:55:57 volumio volumio[4426]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 18 18:55:57 volumio volumio[4426]: info: Streaming services startup Feb 18 18:55:57 volumio volumio[4426]: info: Starting Streaming Daemon Feb 18 18:55:57 volumio sudo[4811]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 18 18:55:57 volumio sudo[4811]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 18:55:57 volumio volumio[4426]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 18 18:55:57 volumio sudo[4811]: pam_unix(sudo:session): session closed for user root Feb 18 18:55:57 volumio volumio[4426]: info: Getting Spotify volume Feb 18 18:55:57 volumio volumio[4426]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 18 18:55:57 volumio volumio[4426]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 18 18:55:57 volumio volumio[4426]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 18 18:55:57 volumio volumio[4426]: errno: -111, Feb 18 18:55:57 volumio volumio[4426]: code: 'ECONNREFUSED', Feb 18 18:55:57 volumio volumio[4426]: syscall: 'connect', Feb 18 18:55:57 volumio volumio[4426]: address: '127.0.0.1', Feb 18 18:55:57 volumio volumio[4426]: port: 9879, Feb 18 18:55:57 volumio volumio[4426]: response: undefined Feb 18 18:55:57 volumio volumio[4426]: } Feb 18 18:55:57 volumio volumio[4426]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 18 18:55:58 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Feb 18 18:55:58 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 18 18:55:58 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 18 18:55:58 volumio go-librespot[4829]: go-librespot daemon starting... Feb 18 18:55:58 volumio go-librespot[4830]: time="2026-02-18T18:55:58+07:00" level=info msg="running go-librespot 0.4.0" Feb 18 18:55:58 volumio go-librespot[4830]: time="2026-02-18T18:55:58+07:00" level=debug msg="app state loaded" Feb 18 18:55:58 volumio go-librespot[4830]: time="2026-02-18T18:55:58+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 18 18:55:59 volumio sudo[4839]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-18 18:54' Feb 18 18:55:59 volumio sudo[4839]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 18 18:55:59 volumio go-librespot[4830]: time="2026-02-18T18:55:59+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 18 18:55:59 volumio go-librespot[4830]: time="2026-02-18T18:55:59+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 18 18:55:59 volumio go-librespot[4830]: time="2026-02-18T18:55:59+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 18 18:55:59 volumio go-librespot[4830]: time="2026-02-18T18:55:59+07:00" level=info msg="zeroconf server listening on port 42043" Feb 18 18:55:59 volumio go-librespot[4830]: time="2026-02-18T18:55:59+07:00" level=debug msg="obtained new client token: AADfYf7Fj96ZOxNyeUAsGYtdc7uXwKRT61wk11TvjNNpoP3y8V1HuO1rRTdbDfwNSbD+N+pivgZkbDrL4g+hCpnLFSexS2ljPn9H+yZQL+NqrP7i3BELgwfMohyviJtBm9XocruPnHRSf4frpxb/Dgc6l2jtBvOqUwjQu6pQYyGLl0Os+fkDibbPOHbg6wl+85Q9xj9yB/yu4esoG6m2ApdL0XOuOav0A+F4/ylo6ckngxhgQ5wE9FkFTQ==" Feb 18 18:55:59 volumio go-librespot[4830]: time="2026-02-18T18:55:59+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 18 18:55:59 volumio go-librespot[4830]: time="2026-02-18T18:55:59+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" 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="b05a530ca81d05eb9a84d0acf82089f0a60b8ee6" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="4ad85e2147d972f0b838d33c21382d2d813b2ae8" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu Dec 25 09:13:19 UTC 2025" VOLUMIO_VERSION="4.084" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="792f09af7488531aecd1aadcaa9b175e"