Feb 25 23:55:00 volumio go-librespot[31618]: time="2026-02-25T23:55:00+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 25 23:55:00 volumio go-librespot[31618]: time="2026-02-25T23:55:00+07:00" level=debug msg="completed keyexchange" Feb 25 23:55:00 volumio go-librespot[31618]: time="2026-02-25T23:55:00+07:00" level=debug msg="completed challenge" Feb 25 23:55:00 volumio go-librespot[31618]: time="2026-02-25T23: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 25 23:55:00 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 23:55:00 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 23:55:00 volumio volumio-remote-updater[647]: [2026-02-25 23:55:00] [connect] Successful connection Feb 25 23:55:00 volumio volumio[31602]: info: MYVOLUMIO Environment detected Feb 25 23:55:00 volumio volumio[31602]: info: Plugin folders cleanup Feb 25 23:55:00 volumio volumio[31602]: info: Scanning into folder /volumio/app/plugins/ Feb 25 23:55:01 volumio volumio[31602]: info: Scanning category audio_interface Feb 25 23:55:01 volumio volumio[31602]: info: Scanning category miscellanea Feb 25 23:55:01 volumio volumio[31602]: info: Scanning category music_service Feb 25 23:55:01 volumio volumio[31602]: info: Scanning category plugins.json Feb 25 23:55:01 volumio volumio[31602]: info: Scanning category system_controller Feb 25 23:55:01 volumio volumio[31602]: info: Scanning category user_interface Feb 25 23:55:01 volumio volumio[31602]: info: Scanning into folder /data/plugins/ Feb 25 23:55:01 volumio volumio[31602]: info: Scanning category music_service Feb 25 23:55:01 volumio volumio[31602]: info: Plugin folders cleanup completed Feb 25 23:55:01 volumio volumio[31602]: info: ------------------------------------------- Feb 25 23:55:01 volumio volumio[31602]: info: ----- Core plugins startup ---- Feb 25 23:55:01 volumio volumio[31602]: info: ------------------------------------------- Feb 25 23:55:01 volumio volumio[31602]: info: Loading plugins from folder /volumio/app/plugins/ Feb 25 23:55:01 volumio volumio[31602]: info: Adding plugin upnp to MyMusic Plugins Feb 25 23:55:01 volumio volumio[31602]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 25 23:55:01 volumio volumio[31602]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 25 23:55:01 volumio volumio[31602]: info: Loading plugins from folder /data/plugins/ Feb 25 23:55:01 volumio volumio[31602]: info: Loading plugin "system"... Feb 25 23:55:01 volumio volumio[31602]: info: Loading plugin "appearance"... Feb 25 23:55:02 volumio volumio[31602]: info: Loading plugin "network"... Feb 25 23:55:03 volumio volumio[31602]: info: Refreshing Cached IP Addresses Feb 25 23:55:03 volumio sudo[31640]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 25 23:55:03 volumio sudo[31640]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 23:55:03 volumio sudo[31642]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 25 23:55:03 volumio sudo[31642]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 23:55:03 volumio sudo[31640]: pam_unix(sudo:session): session closed for user root Feb 25 23:55:03 volumio sudo[31642]: pam_unix(sudo:session): session closed for user root Feb 25 23:55:03 volumio volumio[31602]: info: Loading plugin "services"... Feb 25 23:55:03 volumio volumio[31602]: info: Loading plugin "alsa_controller"... Feb 25 23:55:03 volumio sudo[31651]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 25 23:55:03 volumio sudo[31651]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 23:55:03 volumio volumio[31602]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 25 23:55:03 volumio volumio[31602]: info: Loading plugin "wizard"... Feb 25 23:55:03 volumio volumio[31602]: info: Loading plugin "networkfs"... Feb 25 23:55:03 volumio volumio[31602]: info: Starting Udev Watcher for removable devices Feb 25 23:55:03 volumio volumio[31602]: info: Ignoring mount for partition: boot Feb 25 23:55:03 volumio volumio[31602]: info: Ignoring mount for partition: volumio Feb 25 23:55:03 volumio volumio[31602]: info: Ignoring mount for partition: volumio_data Feb 25 23:55:03 volumio volumio[31602]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 25 23:55:03 volumio volumio[31602]: info: Loading plugin "volumio_command_line_client"... Feb 25 23:55:03 volumio volumio[31602]: info: Loading plugin "upnp"... Feb 25 23:55:03 volumio volumio[31602]: info: [1772038503419] Starting Upmpd Daemon Feb 25 23:55:03 volumio volumio[31602]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 25 23:55:03 volumio volumio[31602]: info: Loading plugin "my_music"... Feb 25 23:55:03 volumio volumio[31602]: info: Loading plugin "mpd"... Feb 25 23:55:03 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Feb 25 23:55:03 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 25 23:55:03 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 25 23:55:03 volumio go-librespot[31673]: go-librespot daemon starting... Feb 25 23:55:03 volumio go-librespot[31674]: time="2026-02-25T23:55:03+07:00" level=info msg="running go-librespot 0.4.0" Feb 25 23:55:03 volumio go-librespot[31674]: time="2026-02-25T23:55:03+07:00" level=debug msg="app state loaded" Feb 25 23:55:03 volumio go-librespot[31674]: time="2026-02-25T23:55:03+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 25 23:55:04 volumio volumio[31602]: info: Loading plugin "upnp_browser"... Feb 25 23:55:04 volumio go-librespot[31674]: time="2026-02-25T23:55: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-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 25 23:55:04 volumio go-librespot[31674]: time="2026-02-25T23:55:04+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 25 23:55:04 volumio go-librespot[31674]: time="2026-02-25T23:55:04+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 25 23:55:04 volumio go-librespot[31674]: time="2026-02-25T23:55:04+07:00" level=info msg="zeroconf server listening on port 39971" Feb 25 23:55:04 volumio go-librespot[31674]: time="2026-02-25T23:55:04+07:00" level=debug msg="obtained new client token: AADySMO4V+4JHqnE6ELRWvNPiYEpO0B5/g7KKck3fiN18q14IY67XLuqWf22enFOzgJagpZ8mZt7gfFaj+W6MPpEAypP0HvDkL6iUuu+pewoLST0s/SuqiZgVWk1I4Ert5hc3CFXYQlskbykYpSxANzxGg/XJzrVvkXvIJwsfVHhQx9gFvmnr5EgGtZvk3/59RMj5Lj7Zf+hsByxPLDYf1pRHnl2lVJllH50OqfQCdXrfv9pA4IijpRhcw==" Feb 25 23:55:04 volumio go-librespot[31674]: time="2026-02-25T23:55:04+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 25 23:55:04 volumio go-librespot[31674]: time="2026-02-25T23:55:04+07:00" level=debug msg="completed keyexchange" Feb 25 23:55:04 volumio go-librespot[31674]: time="2026-02-25T23:55:04+07:00" level=debug msg="completed challenge" Feb 25 23:55:04 volumio go-librespot[31674]: time="2026-02-25T23: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 25 23:55:04 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 23:55:04 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 23:55:05 volumio sudo[31651]: pam_unix(sudo:session): session closed for user root Feb 25 23:55:07 volumio volumio[31602]: info: Starting UPNP Browser Feb 25 23:55:07 volumio volumio[31602]: info: Loading plugin "alarm-clock"... Feb 25 23:55:07 volumio volumio[31602]: info: Loading plugin "airplay_emulation"... Feb 25 23:55:07 volumio volumio[31602]: info: Starting Shairport Sync Feb 25 23:55:07 volumio volumio[31602]: info: Loading plugin "last_100"... Feb 25 23:55:07 volumio volumio[31602]: info: Loading plugin "webradio"... Feb 25 23:55:07 volumio volumio[31602]: info: Loading plugin "i2s_dacs"... Feb 25 23:55:07 volumio volumio[31602]: info: Loading plugin "volumiodiscovery"... Feb 25 23:55:07 volumio volumio[31602]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 25 23:55:07 volumio volumio[31602]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 25 23:55:07 volumio node[31602]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 25 23:55:07 volumio volumio[31602]: *** WARNING *** For more information see Feb 25 23:55:07 volumio volumio[31602]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 25 23:55:07 volumio volumio[31602]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 25 23:55:07 volumio volumio[31602]: *** WARNING *** For more information see Feb 25 23:55:07 volumio node[31602]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 25 23:55:07 volumio node[31602]: *** WARNING *** For more information see Feb 25 23:55:07 volumio node[31602]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 25 23:55:07 volumio node[31602]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 25 23:55:07 volumio node[31602]: *** WARNING *** For more information see Feb 25 23:55:07 volumio volumio[31602]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 25 23:55:07 volumio volumio[31602]: info: Discovery: Started advertising with name: Volumio Feb 25 23:55:07 volumio volumio[31602]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 25 23:55:07 volumio volumio[31602]: info: Loading plugin "spop"... Feb 25 23:55:08 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Feb 25 23:55:08 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 25 23:55:08 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 25 23:55:08 volumio go-librespot[31683]: go-librespot daemon starting... Feb 25 23:55:08 volumio go-librespot[31684]: time="2026-02-25T23:55:08+07:00" level=info msg="running go-librespot 0.4.0" Feb 25 23:55:08 volumio go-librespot[31684]: time="2026-02-25T23:55:08+07:00" level=debug msg="app state loaded" Feb 25 23:55:08 volumio go-librespot[31684]: time="2026-02-25T23:55:08+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 25 23:55:08 volumio go-librespot[31684]: time="2026-02-25T23: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 25 23:55:08 volumio go-librespot[31684]: time="2026-02-25T23:55:08+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 25 23:55:08 volumio go-librespot[31684]: time="2026-02-25T23:55:08+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 25 23:55:08 volumio go-librespot[31684]: time="2026-02-25T23:55:08+07:00" level=info msg="zeroconf server listening on port 42437" Feb 25 23:55:09 volumio go-librespot[31684]: time="2026-02-25T23:55:09+07:00" level=debug msg="obtained new client token: AAB1zSV0HJPO+Uz2I1Uqc0uZ+LIiBiBy+FijdnSd+OMWE9xE000dB2lqS2LNJvpFkveWYg+lrC6fPAhMzIYTIKsM4zFP682UnJjpAWliOJHWgtzCpOw4XNAmTNtGAbgmaZC5ELlhp4DBhawTP1KvF1AM9GZ2GrzCQvU06ZN00Mt80Dj7KirpjhtDHKLL4IUvhUBYPLlW9WVZZFBj3gl4XTbcATHbNtCPK53uwiUEDtkXaItrZodhFbM=" Feb 25 23:55:09 volumio go-librespot[31684]: time="2026-02-25T23:55:09+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 25 23:55:09 volumio go-librespot[31684]: time="2026-02-25T23:55:09+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 25 23:55:09 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 23:55:09 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 23:55:09 volumio volumio[31602]: info: Loading plugin "ytcr"... Feb 25 23:55:12 volumio volumio[31602]: info: Loading plugin "ytmusic"... Feb 25 23:55:12 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Feb 25 23:55:12 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 25 23:55:12 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 25 23:55:12 volumio go-librespot[31692]: go-librespot daemon starting... Feb 25 23:55:12 volumio go-librespot[31693]: time="2026-02-25T23:55:12+07:00" level=info msg="running go-librespot 0.4.0" Feb 25 23:55:12 volumio go-librespot[31693]: time="2026-02-25T23:55:12+07:00" level=debug msg="app state loaded" Feb 25 23:55:12 volumio go-librespot[31693]: time="2026-02-25T23:55:12+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 25 23:55:12 volumio go-librespot[31693]: time="2026-02-25T23: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 25 23:55:12 volumio go-librespot[31693]: time="2026-02-25T23: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 25 23:55:12 volumio go-librespot[31693]: time="2026-02-25T23: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 25 23:55:12 volumio go-librespot[31693]: time="2026-02-25T23:55:12+07:00" level=info msg="zeroconf server listening on port 46477" Feb 25 23:55:13 volumio volumio-remote-updater[647]: [2026-02-25 23:55:13] [connect] Successful connection Feb 25 23:55:13 volumio go-librespot[31693]: time="2026-02-25T23:55:13+07:00" level=debug msg="obtained new client token: AAC94yMJ1mjypQwJ34ICwePyPsWXIz64XqG0FdDefz6d2Q1t8TtlVPvWeAYKrdB7vJvynQZUohoYu6fm4ZGiCtRdGJot76Y5DZQAxTOwQLiOliPhS8OAZM+qVm8IdVskDAc9gu4vgPLHb0h3nkyre04TIkEaFeU9a2TkB3bts1TJ6xBTdnfm0h173o2n3wuLRc8mVbtWjRR8Uea4UIwBm4ZxITVqE6P4UPg8rY8JOwfEKk4lqP7BZaQ=" Feb 25 23:55:13 volumio go-librespot[31693]: time="2026-02-25T23:55:13+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 25 23:55:13 volumio go-librespot[31693]: time="2026-02-25T23:55:13+07:00" level=debug msg="completed keyexchange" Feb 25 23:55:13 volumio go-librespot[31693]: time="2026-02-25T23:55:13+07:00" level=debug msg="completed challenge" Feb 25 23:55:13 volumio volumio[31602]: info: Loading plugin "outputs"... Feb 25 23:55:13 volumio volumio[31602]: info: Loading plugin "albumart"... Feb 25 23:55:13 volumio volumio[31602]: info: Plugin example_plugin is not enabled Feb 25 23:55:13 volumio volumio[31602]: info: Loading plugin "inputs"... Feb 25 23:55:13 volumio go-librespot[31693]: time="2026-02-25T23: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 25 23:55:13 volumio volumio[31602]: info: Loading plugin "updater_comm"... Feb 25 23:55:13 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 23:55:13 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 23:55:13 volumio volumio[31602]: info: Plugin mpdemulation is not enabled Feb 25 23:55:13 volumio volumio[31602]: info: Loading plugin "rest_api"... Feb 25 23:55:13 volumio volumio[31602]: info: Loading plugin "websocket"... Feb 25 23:55:13 volumio volumio[31602]: info: Starting Socket.io Server version 1.7.4 Feb 25 23:55:13 volumio volumio[31602]: info: Loading plugin "RoonBridge"... Feb 25 23:55:14 volumio volumio[31602]: info: Applying required configuration parameters for plugin RoonBridge Feb 25 23:55:14 volumio volumio[31602]: info: Loading i18n strings for locale en Feb 25 23:55:14 volumio volumio[31602]: Updating browse sources language Feb 25 23:55:14 volumio volumio[31602]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 25 23:55:14 volumio volumio[31715]: Forking 3 albumart workers Feb 25 23:55:14 volumio volumio[31602]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 25 23:55:14 volumio volumio[31602]: info: CoreCommandRouter::initPlayerControls Feb 25 23:55:14 volumio volumio[31602]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 23:55:14 volumio volumio[31602]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 23:55:14 volumio volumio[31602]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 23:55:14 volumio volumio[31602]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 23:55:14 volumio volumio[31602]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 23:55:14 volumio volumio[31602]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 23:55:14 volumio volumio[31602]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 23:55:14 volumio volumio[31602]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 23:55:14 volumio volumio[31602]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 25 23:55:14 volumio volumio[31602]: Express server listening on port 3000 Feb 25 23:55:14 volumio volumio[31602]: [Metrics] WebUI: 16s 340.14ms Feb 25 23:55:14 volumio volumio[31602]: info: CoreStateMachine::resetVolumioState Feb 25 23:55:14 volumio volumio[31602]: info: CoreStateMachine::getcurrentVolume Feb 25 23:55:14 volumio volumio[31602]: info: CoreCommandRouter::volumioRetrievevolume Feb 25 23:55:15 volumio sudo[31759]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 25 23:55:15 volumio sudo[31759]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 23:55:15 volumio sudo[31759]: pam_unix(sudo:session): session closed for user root Feb 25 23:55:15 volumio volumio[31602]: info: Volumio Network Manager: Network status updated: 1 Feb 25 23:55:15 volumio sudo[31760]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 25 23:55:15 volumio sudo[31760]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 23:55:15 volumio sudo[31760]: pam_unix(sudo:session): session closed for user root Feb 25 23:55:15 volumio volumio[31602]: info: VolumeController:: Volume=100 Mute =false Feb 25 23:55:15 volumio volumio[31602]: info: CoreStateMachine::pushState Feb 25 23:55:15 volumio volumio[31602]: info: CorePlayQueue::getTrack 0 Feb 25 23:55:15 volumio volumio[31602]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 25 23:55:15 volumio volumio[31602]: info: CoreCommandRouter::volumioPushState Feb 25 23:55:15 volumio volumio[31602]: info: CoreStateMachine::updateTrackBlock Feb 25 23:55:15 volumio volumio[31602]: info: CorePlayQueue::getTrackBlock Feb 25 23:55:15 volumio volumio[31602]: info: CoreCommandRouter::volumioRetrievevolume Feb 25 23:55:15 volumio volumio-remote-updater[647]: [2026-02-25 23:55:15] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1772038513 101 Feb 25 23:55:15 volumio volumio[31602]: 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 25 23:55:15 volumio volumio[31602]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 25 23:55:15 volumio volumio[31602]: info: Reloading queue from file Feb 25 23:55:15 volumio volumio[31602]: info: CoreStateMachine::setRepeat null single undefined Feb 25 23:55:15 volumio volumio[31602]: info: CoreStateMachine::pushState Feb 25 23:55:15 volumio volumio[31602]: info: CorePlayQueue::getTrack 0 Feb 25 23:55:15 volumio volumio[31602]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 25 23:55:15 volumio volumio[31602]: info: CoreCommandRouter::volumioPushState Feb 25 23:55:15 volumio volumio[31602]: info: CoreStateMachine::setRandom null Feb 25 23:55:15 volumio volumio[31602]: info: CoreStateMachine::pushState Feb 25 23:55:15 volumio volumio[31602]: info: CorePlayQueue::getTrack 0 Feb 25 23:55:15 volumio volumio[31602]: info: CoreCommandRouter::volumioPushState Feb 25 23:55:15 volumio volumio[31602]: info: Setting Device type: Raspberry PI Feb 25 23:55:15 volumio volumio[31602]: info: Completed loading Core Plugins Feb 25 23:55:15 volumio volumio[31602]: info: Preparing to generate the ALSA configuration file Feb 25 23:55:16 volumio volumio[31602]: info: VolumeController:: Volume=100 Mute =false Feb 25 23:55:16 volumio volumio[31602]: info: CoreStateMachine::pushState Feb 25 23:55:16 volumio volumio[31602]: info: CorePlayQueue::getTrack 0 Feb 25 23:55:16 volumio volumio[31602]: info: CoreCommandRouter::volumioPushState Feb 25 23:55:16 volumio volumio[31602]: info: Asound.conf file unchanged, so no further update is needed Feb 25 23:55:16 volumio volumio[31602]: info: Output device has changed, restarting MPD Feb 25 23:55:16 volumio volumio[31602]: info: Output device has changed, restarting Shairport Sync Feb 25 23:55:16 volumio sudo[31775]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 25 23:55:16 volumio volumio[31602]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 23:55:16 volumio sudo[31775]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 23:55:16 volumio volumio[31602]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 25 23:55:16 volumio sudo[31779]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 25 23:55:16 volumio sudo[31777]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 25 23:55:16 volumio sudo[31777]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 23:55:16 volumio sudo[31779]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 23:55:16 volumio volumio[31602]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 25 23:55:16 volumio volumio[31602]: info: ___________ START PLUGINS ___________ Feb 25 23:55:16 volumio sudo[31777]: pam_unix(sudo:session): session closed for user root Feb 25 23:55:16 volumio volumio[31602]: info: ControllerMpd::onStart: Initializing MPD Feb 25 23:55:16 volumio volumio[31602]: info: Creating MPD Configuration file Feb 25 23:55:16 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 25 23:55:16 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Feb 25 23:55:16 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 25 23:55:16 volumio volumio[31602]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 25 23:55:16 volumio volumio[31602]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 25 23:55:16 volumio volumio[31602]: info: [1772038516582] CoreMusicLibrary::Adding element Media Servers Feb 25 23:55:16 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 25 23:55:16 volumio go-librespot[31790]: go-librespot daemon starting... Feb 25 23:55:16 volumio volumio[31602]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 25 23:55:16 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 25 23:55:16 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 25 23:55:16 volumio systemd[1]: mpd.service: Consumed 6.859s CPU time. Feb 25 23:55:16 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 25 23:55:16 volumio sudo[31791]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 25 23:55:16 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 25 23:55:16 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 25 23:55:16 volumio sudo[31791]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 23:55:16 volumio sudo[31775]: pam_unix(sudo:session): session closed for user root Feb 25 23:55:16 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 25 23:55:16 volumio go-librespot[31792]: time="2026-02-25T23:55:16+07:00" level=info msg="running go-librespot 0.4.0" Feb 25 23:55:16 volumio go-librespot[31792]: time="2026-02-25T23:55:16+07:00" level=debug msg="app state loaded" Feb 25 23:55:16 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 25 23:55:16 volumio go-librespot[31792]: time="2026-02-25T23:55:16+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 25 23:55:16 volumio volumio[31602]: info: UPNP Browser: Client initialized successfully Feb 25 23:55:16 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 25 23:55:16 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 25 23:55:16 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 25 23:55:16 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 25 23:55:16 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 25 23:55:16 volumio volumio[31602]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 23:55:16 volumio volumio[31602]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 25 23:55:16 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 25 23:55:16 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 25 23:55:17 volumio sudo[31788]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 25 23:55:17 volumio sudo[31788]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 23:55:17 volumio sudo[31788]: pam_unix(sudo:session): session closed for user root Feb 25 23:55:17 volumio volumio[31602]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 25 23:55:17 volumio volumio[31602]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 23:55:17 volumio volumio[31602]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 25 23:55:17 volumio volumio[31602]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 25 23:55:17 volumio volumio[31602]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 25 23:55:17 volumio volumio[31602]: info: [1772038517280] CoreMusicLibrary::Adding element Last_100 Feb 25 23:55:17 volumio volumio[31602]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 25 23:55:17 volumio volumio[31602]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 25 23:55:17 volumio volumio[31602]: info: [1772038517310] CoreMusicLibrary::Adding element Webradio Feb 25 23:55:17 volumio volumio[31602]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 25 23:55:17 volumio volumio[31602]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 25 23:55:17 volumio volumio[31602]: info: Initializing BBC Radios Feb 25 23:55:17 volumio go-librespot[31792]: time="2026-02-25T23:55:17+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 25 23:55:17 volumio go-librespot[31792]: time="2026-02-25T23:55:17+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 25 23:55:17 volumio go-librespot[31792]: time="2026-02-25T23:55:17+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 25 23:55:17 volumio sudo[31805]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 25 23:55:17 volumio sudo[31805]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 25 23:55:17 volumio go-librespot[31792]: time="2026-02-25T23:55:17+07:00" level=info msg="zeroconf server listening on port 34623" Feb 25 23:55:17 volumio sudo[31805]: pam_unix(sudo:session): session closed for user root Feb 25 23:55:17 volumio volumio[31602]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 25 23:55:17 volumio volumio[31602]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 25 23:55:17 volumio volumio[31602]: info: Creating Spotify config file Feb 25 23:55:17 volumio volumio[31602]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 23:55:17 volumio go-librespot[31792]: time="2026-02-25T23:55:17+07:00" level=debug msg="obtained new client token: AAB5OlkPhm2eirxvAKhKOBoeMt/cyhB8s9RLRtCb1t+fBtXSskjnxXcw+zjpW7orWCuFIJYxLXSGL1pxOLcOqdRjpr3GCYczXMIG0KP9RAwF/rGWjTTdpz9XGHdjozhyG5RY5B3PnmIHw2QNcuO8UrBiVEa/7Us+sLsbcMDoPi8pODb1Mvuc73wUF7MhjXLeHikCwfcJU0w/dLNj7SBbCOcYyFCL/k90A/SKj0MWIhgojcEEjsFirX4/Uw==" Feb 25 23:55:17 volumio go-librespot[31792]: time="2026-02-25T23:55:17+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 25 23:55:18 volumio go-librespot[31792]: time="2026-02-25T23:55:18+07:00" level=debug msg="completed keyexchange" Feb 25 23:55:18 volumio go-librespot[31792]: time="2026-02-25T23:55:18+07:00" level=debug msg="completed challenge" Feb 25 23:55:18 volumio go-librespot[31792]: time="2026-02-25T23:55:18+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 25 23:55:18 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 23:55:18 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 23:55:19 volumio volumio[31726]: Starting albumart workers Feb 25 23:55:19 volumio volumio[31725]: Starting albumart workers Feb 25 23:55:19 volumio volumio[31727]: Starting albumart workers Feb 25 23:55:19 volumio volumio[31602]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 25 23:55:19 volumio volumio[31602]: info: [1772038519615] CoreMusicLibrary::Adding element YouTube Music Feb 25 23:55:19 volumio volumio[31602]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 25 23:55:19 volumio volumio[31602]: Cannot find translation for source YouTube Music Feb 25 23:55:19 volumio volumio[31602]: info: Volumio Calling Home Feb 25 23:55:19 volumio sudo[31829]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 25 23:55:19 volumio sudo[31829]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 23:55:20 volumio sudo[31829]: pam_unix(sudo:session): session closed for user root Feb 25 23:55:20 volumio volumio[31602]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 25 23:55:20 volumio volumio[31602]: info: Discovery: Found device Volumio Feb 25 23:55:20 volumio volumio[31602]: info: CoreCommandRouter::volumioGetState Feb 25 23:55:20 volumio volumio[31602]: info: CorePlayQueue::getTrack 0 Feb 25 23:55:20 volumio volumio[31602]: info: MPD Permissions set Feb 25 23:55:20 volumio volumio[31602]: info: MPD Permissions set Feb 25 23:55:20 volumio volumio[31602]: info: Upmpdcli Daemon Started Feb 25 23:55:20 volumio volumio[31602]: info: Spotify config file written Feb 25 23:55:21 volumio sudo[31835]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 25 23:55:21 volumio sudo[31835]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 23:55:21 volumio volumio[31602]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 25 23:55:21 volumio volumio[31602]: info: Discovery: Found device Volumio Feb 25 23:55:21 volumio volumio[31602]: info: CoreCommandRouter::volumioGetState Feb 25 23:55:21 volumio volumio[31602]: info: CorePlayQueue::getTrack 0 Feb 25 23:55:21 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Feb 25 23:55:21 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 25 23:55:21 volumio volumio[31602]: 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 25 23:55:21 volumio go-librespot[31837]: go-librespot daemon starting... Feb 25 23:55:21 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 25 23:55:21 volumio volumio[31602]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 23:55:21 volumio volumio[31602]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 23:55:21 volumio volumio[31602]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 23:55:21 volumio volumio[31602]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 23:55:21 volumio volumio[31602]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 23:55:21 volumio volumio[31602]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 23:55:21 volumio volumio[31602]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 23:55:21 volumio volumio[31602]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 23:55:21 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 25 23:55:21 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 25 23:55:21 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 25 23:55:21 volumio go-librespot[31842]: go-librespot daemon starting... Feb 25 23:55:21 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 25 23:55:21 volumio volumio[31602]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 25 23:55:21 volumio sudo[31835]: pam_unix(sudo:session): session closed for user root Feb 25 23:55:21 volumio volumio[31602]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 23:55:21 volumio volumio[31602]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 23:55:21 volumio go-librespot[31846]: time="2026-02-25T23:55:21+07:00" level=info msg="running go-librespot 0.4.0" Feb 25 23:55:21 volumio volumio[31602]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 23:55:21 volumio volumio[31602]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 23:55:21 volumio go-librespot[31846]: time="2026-02-25T23:55:21+07:00" level=debug msg="app state loaded" Feb 25 23:55:21 volumio volumio[31602]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 23:55:21 volumio volumio[31602]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 23:55:21 volumio volumio[31602]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 23:55:21 volumio go-librespot[31846]: time="2026-02-25T23:55:21+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 25 23:55:21 volumio volumio[31602]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 23:55:21 volumio volumio[31602]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 23:55:21 volumio volumio[31602]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 25 23:55:21 volumio volumio[31602]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 23:55:21 volumio volumio[31602]: info: No need to fix Spotify hosts Feb 25 23:55:22 volumio go-librespot[31846]: time="2026-02-25T23:55:22+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 25 23:55:22 volumio go-librespot[31846]: time="2026-02-25T23:55:22+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 25 23:55:22 volumio go-librespot[31846]: time="2026-02-25T23:55:22+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 25 23:55:22 volumio go-librespot[31846]: time="2026-02-25T23:55:22+07:00" level=info msg="zeroconf server listening on port 45691" Feb 25 23:55:22 volumio volumio[31602]: info: Volumio called home Feb 25 23:55:22 volumio go-librespot[31846]: time="2026-02-25T23:55:22+07:00" level=debug msg="obtained new client token: AABzl7pIwZosylokGFKBtZYGPqX8aGUdmhlaaZt3IVsvNylhNDEN32ZkZbpO18nm2X4rq7ReNko1uLtCMzt5qwcJwDgAygizBSYTaVc/Yr3Zkw9O2VCjE+fUVSQ6h131TcURwGD7gsQb8BO1ZLyQ9a3M4X1VHMFYHUJJeeKMLXPNMz9CV7utrZmjMSUG1QPG7ent0AQknVXb7gmToHNP3fLoMzE3oPBL05od/Q/OWuS46vGiPfl+YI/t2w==" Feb 25 23:55:22 volumio go-librespot[31846]: time="2026-02-25T23:55:22+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 25 23:55:23 volumio go-librespot[31846]: time="2026-02-25T23:55:23+07:00" level=debug msg="completed keyexchange" Feb 25 23:55:23 volumio go-librespot[31846]: time="2026-02-25T23:55:23+07:00" level=debug msg="completed challenge" Feb 25 23:55:23 volumio go-librespot[31846]: time="2026-02-25T23:55:23+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 25 23:55:23 volumio volumio[31602]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 25 23:55:23 volumio volumio[31602]: SPOTIFY: BQCnPi1Y4Kcbkniyl2AxtJzsDy0PmV1HGLyxUSx6AUTY7AVD2mUv_TTbWPKUYZYCKZRpyzg_F4rEsinAqMRDwlfLkZNKHgR4C5XIApLt5fXRZUieNDOa4ppcaom7rR8bYKbZTndYrSyGK9iYoHD7VE51wKZzoMdZlmKIbaI3RNb-61_wasF-kPt47NUI-v8NRQMWWYekGydqzTQdDI97mMfs-865Q_f_R75ZWwnDypln9kSUDksa35p6H-4KENuU6t0NJ0K9uFfbGwSWdTUBWxKprVByDk6BYo4nHIPibya9gpQMjFcJYD_J Feb 25 23:55:23 volumio volumio[31602]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 25 23:55:23 volumio volumio[31602]: info: New Spotify access token = BQCnPi1Y4Kcbkniyl2AxtJzsDy0PmV1HGLyxUSx6AUTY7AVD2mUv_TTbWPKUYZYCKZRpyzg_F4rEsinAqMRDwlfLkZNKHgR4C5XIApLt5fXRZUieNDOa4ppcaom7rR8bYKbZTndYrSyGK9iYoHD7VE51wKZzoMdZlmKIbaI3RNb-61_wasF-kPt47NUI-v8NRQMWWYekGydqzTQdDI97mMfs-865Q_f_R75ZWwnDypln9kSUDksa35p6H-4KENuU6t0NJ0K9uFfbGwSWdTUBWxKprVByDk6BYo4nHIPibya9gpQMjFcJYD_J Feb 25 23:55:23 volumio volumio[31602]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 25 23:55:23 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 23:55:23 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 23:55:23 volumio volumio[31602]: info: Starting Shairport Sync Feb 25 23:55:23 volumio volumio[31602]: info: Starting Shairport Sync Feb 25 23:55:23 volumio volumio[31602]: info: Starting Shairport Sync Feb 25 23:55:23 volumio sudo[31877]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 25 23:55:23 volumio sudo[31877]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 23:55:23 volumio sudo[31881]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 25 23:55:23 volumio sudo[31881]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 23:55:23 volumio sudo[31879]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 25 23:55:23 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 25 23:55:23 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 25 23:55:23 volumio sudo[31879]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 23:55:23 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 25 23:55:23 volumio systemd[1]: shairport-sync.service: Consumed 2.358s CPU time. Feb 25 23:55:23 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 25 23:55:23 volumio sudo[31877]: pam_unix(sudo:session): session closed for user root Feb 25 23:55:23 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 25 23:55:23 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 25 23:55:23 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 25 23:55:23 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 25 23:55:23 volumio sudo[31881]: pam_unix(sudo:session): session closed for user root Feb 25 23:55:23 volumio sudo[31879]: pam_unix(sudo:session): session closed for user root Feb 25 23:55:23 volumio volumio[31602]: info: Shairport-Sync Started Feb 25 23:55:24 volumio volumio[31602]: Error adding Membership: Error: addMembership EINVAL Feb 25 23:55:24 volumio volumio[31602]: info: Shairport-Sync Started Feb 25 23:55:24 volumio volumio[31602]: info: Shairport-Sync Started Feb 25 23:55:24 volumio volumio[31602]: info: CoreCommandRouter::volumioGetState Feb 25 23:55:24 volumio volumio[31602]: info: CorePlayQueue::getTrack 0 Feb 25 23:55:24 volumio volumio[31602]: 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 25 23:55:24 volumio volumio[31602]: info: Spotify Successfully logged in Feb 25 23:55:24 volumio volumio[31602]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 25 23:55:24 volumio volumio[31602]: info: [1772038524235] CoreMusicLibrary::Adding element Spotify Feb 25 23:55:24 volumio volumio[31602]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 25 23:55:24 volumio volumio[31602]: Cannot find translation for source YouTube Music Feb 25 23:55:24 volumio volumio[31602]: Cannot find translation for source Spotify Feb 25 23:55:24 volumio mpd[31822]: 2026-02-25T23:55:24 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 25 23:55:24 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 25 23:55:24 volumio sudo[31779]: pam_unix(sudo:session): session closed for user root Feb 25 23:55:24 volumio sudo[31791]: pam_unix(sudo:session): session closed for user root Feb 25 23:55:24 volumio volumio[31602]: error: MPD error: The expression evaluated to a falsy value: Feb 25 23:55:24 volumio volumio[31602]: assert.ok(self.idling) Feb 25 23:55:24 volumio volumio[31602]: error: The expression evaluated to a falsy value: Feb 25 23:55:24 volumio volumio[31602]: assert.ok(self.idling) Feb 25 23:55:24 volumio volumio[31602]: error: updateQueue error: null Feb 25 23:55:24 volumio volumio[31602]: info: MPD running with PID31822 Feb 25 23:55:24 volumio volumio[31602]: ,establishing connection Feb 25 23:55:24 volumio volumio[31602]: error: updateQueue error: null Feb 25 23:55:25 volumio volumio[31602]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 25 23:55:25 volumio volumio[31602]: info: CoreCommandRouter::volumioRetrievevolume Feb 25 23:55:25 volumio volumio[31602]: info: VolumeController:: Volume=100 Mute =false Feb 25 23:55:25 volumio volumio[31602]: info: CoreCommandRouter::volumioGetState Feb 25 23:55:25 volumio volumio[31602]: info: CorePlayQueue::getTrack 0 Feb 25 23:55:25 volumio volumio[31602]: info: CoreStateMachine::pushState Feb 25 23:55:25 volumio volumio[31602]: info: CorePlayQueue::getTrack 0 Feb 25 23:55:25 volumio volumio[31602]: info: CoreCommandRouter::volumioPushState Feb 25 23:55:25 volumio volumio[31602]: info: Completed starting Core Plugins Feb 25 23:55:25 volumio volumio[31602]: info: ------------------------------------------- Feb 25 23:55:25 volumio volumio[31602]: info: ----- MyVolumio plugins startup ---- Feb 25 23:55:25 volumio volumio[31602]: info: ------------------------------------------- Feb 25 23:55:25 volumio volumio[31602]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 25 23:55:26 volumio volumio[31602]: info: go-librespot daemon successfully initialized Feb 25 23:55:26 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 25 23:55:26 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 25 23:55:26 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 25 23:55:26 volumio go-librespot[31922]: go-librespot daemon starting... Feb 25 23:55:26 volumio go-librespot[31923]: time="2026-02-25T23:55:26+07:00" level=info msg="running go-librespot 0.4.0" Feb 25 23:55:26 volumio go-librespot[31923]: time="2026-02-25T23:55:26+07:00" level=debug msg="app state loaded" Feb 25 23:55:26 volumio go-librespot[31923]: time="2026-02-25T23:55:26+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 25 23:55:27 volumio go-librespot[31923]: time="2026-02-25T23:55:27+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 25 23:55:27 volumio go-librespot[31923]: time="2026-02-25T23:55:27+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 25 23:55:27 volumio go-librespot[31923]: time="2026-02-25T23:55:27+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 25 23:55:27 volumio go-librespot[31923]: time="2026-02-25T23:55:27+07:00" level=info msg="zeroconf server listening on port 35035" Feb 25 23:55:27 volumio go-librespot[31923]: time="2026-02-25T23:55:27+07:00" level=debug msg="obtained new client token: AACGQi0RC0xVBGzJKn24EQvz1umhLt2UKeeHYImdopyxnYSRPJ4FlfT9m93n5lIIpwd/YM/eT7t0Q+FBOZpD/GXNkVjsDOqDtSLZ/KEnXLd9n2c/IGKXo6f4jEKKVpx137auBj4fToZmdZuff1kwKfO78/WEFB0kcYAT3B8s70t0N6tj/WqTRVbfB+2GAbaYd2vcLVTj++CjOxUrbwfroK4d72G1FJ1JYcFs0qhVAfGXdRzaKOhWe7U=" Feb 25 23:55:27 volumio go-librespot[31923]: time="2026-02-25T23:55:27+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 25 23:55:27 volumio go-librespot[31923]: time="2026-02-25T23:55:27+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 25 23:55:27 volumio go-librespot[31923]: time="2026-02-25T23:55:27+07:00" level=debug msg="completed keyexchange" Feb 25 23:55:27 volumio go-librespot[31923]: time="2026-02-25T23:55:27+07:00" level=debug msg="completed challenge" Feb 25 23:55:27 volumio go-librespot[31923]: time="2026-02-25T23:55:27+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 25 23:55:27 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 23:55:27 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 23:55:29 volumio volumio[31602]: info: Initializing connection to go-librespot Websocket Feb 25 23:55:29 volumio volumio[31602]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 25 23:55:29 volumio volumio[31602]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 25 23:55:30 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 25 23:55:30 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 25 23:55:30 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 25 23:55:30 volumio go-librespot[31930]: go-librespot daemon starting... Feb 25 23:55:30 volumio go-librespot[31931]: time="2026-02-25T23:55:30+07:00" level=info msg="running go-librespot 0.4.0" Feb 25 23:55:30 volumio go-librespot[31931]: time="2026-02-25T23:55:30+07:00" level=debug msg="app state loaded" Feb 25 23:55:30 volumio go-librespot[31931]: time="2026-02-25T23:55:30+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 25 23:55:31 volumio go-librespot[31931]: time="2026-02-25T23:55:31+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 25 23:55:31 volumio go-librespot[31931]: time="2026-02-25T23:55:31+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 25 23:55:31 volumio go-librespot[31931]: time="2026-02-25T23:55:31+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 25 23:55:31 volumio go-librespot[31931]: time="2026-02-25T23:55:31+07:00" level=info msg="zeroconf server listening on port 35843" Feb 25 23:55:31 volumio go-librespot[31931]: time="2026-02-25T23:55:31+07:00" level=debug msg="obtained new client token: AAAXPu/1h4xv0kSQCvzJa1DB/yIa5483dtEFy174HrlQmafZuac5OU9iOeXv4PrD5eYm5VhdUpFPqMHcsisI0xG2olIQkTBZK/wt5EZOXuzssiOH0nbMdNFqpQgP2iJlFQlG59CuSPZlalyh6QwdSWCE0aHYbJV6JZc6j5SJ8vYQXxuSzU13L+zizpF8XHvbAxGCOorstk1VnXbjDrcVFeUFQz7l/y+9Ac5l6BfZ7fsF34aPybxsbDtlng==" Feb 25 23:55:31 volumio go-librespot[31931]: time="2026-02-25T23:55:31+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 25 23:55:31 volumio go-librespot[31931]: time="2026-02-25T23:55:31+07:00" level=debug msg="completed keyexchange" Feb 25 23:55:31 volumio go-librespot[31931]: time="2026-02-25T23:55:31+07:00" level=debug msg="completed challenge" Feb 25 23:55:31 volumio go-librespot[31931]: time="2026-02-25T23:55:31+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 25 23:55:31 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 23:55:31 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 23:55:32 volumio volumio[31602]: info: Initializing connection to go-librespot Websocket Feb 25 23:55:32 volumio volumio[31602]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 25 23:55:34 volumio volumio[31602]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 25 23:55:34 volumio volumio[31602]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 25 23:55:34 volumio volumio[31602]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 25 23:55:34 volumio volumio[31602]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 25 23:55:34 volumio volumio[31602]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 25 23:55:34 volumio volumio[31602]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 25 23:55:34 volumio volumio[31602]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 25 23:55:34 volumio volumio[31602]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 25 23:55:34 volumio volumio[31602]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 25 23:55:34 volumio volumio[31602]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 25 23:55:34 volumio volumio[31602]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 25 23:55:34 volumio volumio[31602]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 25 23:55:34 volumio volumio[31602]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 25 23:55:34 volumio volumio[31602]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 25 23:55:34 volumio volumio[31602]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 25 23:55:34 volumio volumio[31602]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 25 23:55:34 volumio volumio[31602]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 25 23:55:34 volumio volumio[31602]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 25 23:55:34 volumio volumio[31602]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 25 23:55:34 volumio volumio[31602]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 25 23:55:34 volumio volumio[31602]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 25 23:55:34 volumio volumio[31602]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 25 23:55:34 volumio volumio[31602]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 25 23:55:34 volumio volumio[31602]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 25 23:55:34 volumio volumio[31602]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 25 23:55:34 volumio volumio[31602]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 25 23:55:34 volumio volumio[31602]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 25 23:55:34 volumio volumio[31602]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 25 23:55:34 volumio volumio[31602]: info: Adding plugin bluetooth to MyMusic Plugins Feb 25 23:55:34 volumio volumio[31602]: info: Adding plugin multiroom to MyMusic Plugins Feb 25 23:55:34 volumio volumio[31602]: info: Adding plugin metavolumio to MyMusic Plugins Feb 25 23:55:34 volumio volumio[31602]: info: Adding plugin cd_controller to MyMusic Plugins Feb 25 23:55:34 volumio volumio[31602]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 25 23:55:34 volumio volumio[31602]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 25 23:55:34 volumio volumio[31602]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 25 23:55:34 volumio volumio[31602]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 25 23:55:35 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 25 23:55:35 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 25 23:55:35 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 25 23:55:35 volumio go-librespot[31953]: go-librespot daemon starting... Feb 25 23:55:35 volumio go-librespot[31954]: time="2026-02-25T23:55:35+07:00" level=info msg="running go-librespot 0.4.0" Feb 25 23:55:35 volumio go-librespot[31954]: time="2026-02-25T23:55:35+07:00" level=debug msg="app state loaded" Feb 25 23:55:35 volumio go-librespot[31954]: time="2026-02-25T23:55:35+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 25 23:55:35 volumio go-librespot[31954]: time="2026-02-25T23:55:35+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 25 23:55:35 volumio go-librespot[31954]: time="2026-02-25T23:55:35+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 25 23:55:35 volumio go-librespot[31954]: time="2026-02-25T23:55:35+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 25 23:55:35 volumio go-librespot[31954]: time="2026-02-25T23:55:35+07:00" level=info msg="zeroconf server listening on port 34389" Feb 25 23:55:36 volumio go-librespot[31954]: time="2026-02-25T23:55:36+07:00" level=debug msg="obtained new client token: AABnwkVDQ/yDfCzpZBxfEhdMOtHy5E9GhuaFCtbDb939ap718LWA8u+7r66hriXaG7QdxRj9rxBIU+djcrV4/1G7M/6jfbX+CqLqQcmAqa/j/wZXb1da0EqsX5WPCI1oP1LdBzItFJhpoNHiCVEmHeMJH9++ord0EP4ZH9SCQZKyOSdLY+MOR6OpnC4HPVynMAJcP2WMMKnGyiRx6wFigo2vvZiR2K8dOOy8TGXDNCQg+ASwy8JHFfW0Eg==" Feb 25 23:55:36 volumio go-librespot[31954]: time="2026-02-25T23:55:36+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 25 23:55:36 volumio volumio[31602]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 25 23:55:36 volumio volumio[31602]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 25 23:55:36 volumio volumio[31602]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 25 23:55:36 volumio volumio[31602]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 25 23:55:36 volumio volumio[31602]: info: Starting MyVolumio Remote Streaming Endpoints Feb 25 23:55:36 volumio go-librespot[31954]: time="2026-02-25T23:55:36+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 25 23:55:36 volumio volumio[31602]: info: MyVolumio login type: Token Feb 25 23:55:36 volumio volumio[31602]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 25 23:55:36 volumio volumio[31602]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 25 23:55:36 volumio go-librespot[31954]: time="2026-02-25T23:55:36+07:00" level=debug msg="completed keyexchange" Feb 25 23:55:36 volumio go-librespot[31954]: time="2026-02-25T23:55:36+07:00" level=debug msg="completed challenge" Feb 25 23:55:36 volumio go-librespot[31954]: time="2026-02-25T23:55:36+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 25 23:55:36 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 23:55:36 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 23:55:38 volumio volumio[31602]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 25 23:55:38 volumio volumio[31602]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 25 23:55:38 volumio volumio[31602]: info: Streaming services startup Feb 25 23:55:38 volumio volumio[31602]: info: Starting Streaming Daemon Feb 25 23:55:38 volumio sudo[31962]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 25 23:55:38 volumio sudo[31962]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 23:55:38 volumio volumio[31602]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 25 23:55:38 volumio sudo[31962]: pam_unix(sudo:session): session closed for user root Feb 25 23:55:38 volumio volumio[31602]: info: Initializing connection to go-librespot Websocket Feb 25 23:55:38 volumio volumio[31602]: error: Cannot start Volumio Streaming Daemon Feb 25 23:55:38 volumio volumio[31602]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 25 23:55:38 volumio volumio[31602]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 25 23:55:38 volumio volumio[31602]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 25 23:55:39 volumio volumio[31602]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Feb 25 23:55:39 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Feb 25 23:55:39 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 25 23:55:39 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 25 23:55:39 volumio go-librespot[31970]: go-librespot daemon starting... Feb 25 23:55:39 volumio go-librespot[31971]: time="2026-02-25T23:55:39+07:00" level=info msg="running go-librespot 0.4.0" Feb 25 23:55:39 volumio go-librespot[31971]: time="2026-02-25T23:55:39+07:00" level=debug msg="app state loaded" Feb 25 23:55:39 volumio go-librespot[31971]: time="2026-02-25T23:55:39+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 25 23:55:40 volumio volumio[31602]: info: MyVolumio token set successfully Feb 25 23:55:40 volumio volumio[31602]: info: MYVOLUMIO: Adding device Feb 25 23:55:40 volumio volumio[31602]: info: MYVOLUMIO: Evaluating Server Feb 25 23:55:40 volumio go-librespot[31971]: time="2026-02-25T23:55:40+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 25 23:55:40 volumio go-librespot[31971]: time="2026-02-25T23:55:40+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 25 23:55:40 volumio go-librespot[31971]: time="2026-02-25T23:55:40+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 25 23:55:40 volumio go-librespot[31971]: time="2026-02-25T23:55:40+07:00" level=info msg="zeroconf server listening on port 32887" Feb 25 23:55:40 volumio go-librespot[31971]: time="2026-02-25T23:55:40+07:00" level=debug msg="obtained new client token: AAD9t3Uh4D+Pv1tSxpp5XfSJ4lTQePNGGEhm4muQby5G5rhc/NOGAcCbpSbiiZqJ+Hby6iAVWOCOwXU3qh6X0VQvGmxOzTYCCBrqBy2QGGULIUevKbsB2Jjkvt2NvgsuAxLC2Pznu1fl58tunTs5WtMgI/nifhaCZrPRJu3j5HkKAC7BYzSqZo6vNJV+i1WAD4iSbyW5o2FdZocZqfiFr0TUresxeenbZDqII6na+so8zDa8AkdtLG2tEg==" Feb 25 23:55:40 volumio go-librespot[31971]: time="2026-02-25T23:55:40+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 25 23:55:40 volumio go-librespot[31971]: time="2026-02-25T23:55:40+07:00" level=debug msg="completed keyexchange" Feb 25 23:55:40 volumio go-librespot[31971]: time="2026-02-25T23:55:40+07:00" level=debug msg="completed challenge" Feb 25 23:55:40 volumio volumio[31602]: info: MyVolumio status changed Feb 25 23:55:40 volumio volumio[31602]: info: Streaming services startup Feb 25 23:55:40 volumio volumio[31602]: info: Starting Streaming Daemon Feb 25 23:55:40 volumio volumio[31602]: info: Removing browser output: myVolumio user plan is not superstar Feb 25 23:55:40 volumio volumio[31602]: info: Removing audio output: Feb 25 23:55:40 volumio volumio[31602]: info: Stoppping Tunnel 1 Feb 25 23:55:40 volumio go-librespot[31971]: time="2026-02-25T23:55:40+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 25 23:55:40 volumio sudo[32000]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 25 23:55:40 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 23:55:40 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 23:55:40 volumio sudo[32000]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 23:55:40 volumio sudo[32000]: pam_unix(sudo:session): session closed for user root Feb 25 23:55:40 volumio sudo[32003]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Feb 25 23:55:40 volumio sudo[32003]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 23:55:40 volumio volumio[31602]: error: Cannot start Volumio Streaming Daemon Feb 25 23:55:40 volumio volumio[31602]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 25 23:55:40 volumio volumio[31602]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 25 23:55:40 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 25 23:55:40 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 25 23:55:40 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 25 23:55:40 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 25 23:55:40 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 25 23:55:40 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 25 23:55:40 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 25 23:55:40 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Feb 25 23:55:40 volumio sudo[32003]: pam_unix(sudo:session): session closed for user root Feb 25 23:55:41 volumio volumio[31602]: info: Remote SSH Stopped Feb 25 23:55:41 volumio volumio[31602]: info: Initializing connection to go-librespot Websocket Feb 25 23:55:41 volumio volumio[31602]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 25 23:55:42 volumio volumio[31602]: info: Setting Geolocation for MyVolumio to as1 Feb 25 23:55:42 volumio volumio[31602]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 25 23:55:42 volumio volumio[31602]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 25 23:55:42 volumio volumio[31602]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 25 23:55:43 volumio volumio[31602]: info: Updating MyVolumio device info Feb 25 23:55:43 volumio volumio[31602]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 25 23:55:43 volumio volumio[31602]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 25 23:55:43 volumio volumio[31602]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 25 23:55:43 volumio volumio[31602]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Feb 25 23:55:43 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Feb 25 23:55:43 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 25 23:55:43 volumio volumio[31602]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Feb 25 23:55:43 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 25 23:55:43 volumio go-librespot[32019]: go-librespot daemon starting... Feb 25 23:55:43 volumio go-librespot[32020]: time="2026-02-25T23:55:43+07:00" level=info msg="running go-librespot 0.4.0" Feb 25 23:55:43 volumio go-librespot[32020]: time="2026-02-25T23:55:43+07:00" level=debug msg="app state loaded" Feb 25 23:55:43 volumio go-librespot[32020]: time="2026-02-25T23:55:43+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 25 23:55:44 volumio volumio[31602]: info: Initializing connection to go-librespot Websocket Feb 25 23:55:44 volumio go-librespot[32020]: time="2026-02-25T23:55:44+07:00" level=debug msg="new websocket client" Feb 25 23:55:44 volumio volumio[31602]: info: Connection to go-librespot Websocket established Feb 25 23:55:44 volumio go-librespot[32020]: time="2026-02-25T23:55:44+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 25 23:55:44 volumio go-librespot[32020]: time="2026-02-25T23:55:44+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 25 23:55:44 volumio go-librespot[32020]: time="2026-02-25T23:55:44+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 25 23:55:44 volumio go-librespot[32020]: time="2026-02-25T23:55:44+07:00" level=info msg="zeroconf server listening on port 34429" Feb 25 23:55:44 volumio go-librespot[32020]: time="2026-02-25T23:55:44+07:00" level=debug msg="obtained new client token: AADePKLK8LyZe2wTsr6FltcuCl5/ZoXfrOCfVPUeDcVVwQEw4CNesKH2bnaj4//j7oml/XbIi+rS51bK9vhdISkfpmn/6CoZG4pvkNwiUjAWtAZcQlNzFz9mC1Miv1bDmLLK5FolwzMzZdUtQZCzzRy3a/qBxh8OZ3q2QCdTQlzSvQKSP1WpCEBhF42a90kSpsEdu0w9qr2t9dpDESnRZyK1qgo/J2Gu3X8Y3wtRHl5CJvxfSfEjkIdNPw==" Feb 25 23:55:44 volumio go-librespot[32020]: time="2026-02-25T23:55:44+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 25 23:55:44 volumio go-librespot[32020]: time="2026-02-25T23:55:44+07:00" level=debug msg="completed keyexchange" Feb 25 23:55:44 volumio go-librespot[32020]: time="2026-02-25T23:55:44+07:00" level=debug msg="completed challenge" Feb 25 23:55:45 volumio go-librespot[32020]: time="2026-02-25T23:55:45+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 25 23:55:45 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 23:55:45 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 23:55:45 volumio volumio[31602]: info: Connection to go-librespot Websocket closed Feb 25 23:55:47 volumio volumio[31602]: info: Getting Spotify volume Feb 25 23:55:47 volumio volumio[31602]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 25 23:55:47 volumio volumio[31602]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 25 23:55:47 volumio volumio[31602]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 25 23:55:47 volumio volumio[31602]: errno: -111, Feb 25 23:55:47 volumio volumio[31602]: code: 'ECONNREFUSED', Feb 25 23:55:47 volumio volumio[31602]: syscall: 'connect', Feb 25 23:55:47 volumio volumio[31602]: address: '127.0.0.1', Feb 25 23:55:47 volumio volumio[31602]: port: 9879, Feb 25 23:55:47 volumio volumio[31602]: response: undefined Feb 25 23:55:47 volumio volumio[31602]: } Feb 25 23:55:47 volumio volumio[31602]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 25 23:55:48 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Feb 25 23:55:48 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 25 23:55:48 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 25 23:55:48 volumio go-librespot[32039]: go-librespot daemon starting... Feb 25 23:55:48 volumio go-librespot[32040]: time="2026-02-25T23:55:48+07:00" level=info msg="running go-librespot 0.4.0" Feb 25 23:55:48 volumio go-librespot[32040]: time="2026-02-25T23:55:48+07:00" level=debug msg="app state loaded" Feb 25 23:55:48 volumio go-librespot[32040]: time="2026-02-25T23:55:48+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 25 23:55:48 volumio go-librespot[32040]: time="2026-02-25T23:55:48+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 25 23:55:48 volumio go-librespot[32040]: time="2026-02-25T23:55:48+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 25 23:55:48 volumio go-librespot[32040]: time="2026-02-25T23:55:48+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 25 23:55:48 volumio go-librespot[32040]: time="2026-02-25T23:55:48+07:00" level=info msg="zeroconf server listening on port 46527" Feb 25 23:55:48 volumio go-librespot[32040]: time="2026-02-25T23:55:48+07:00" level=debug msg="obtained new client token: AADhF7R/qlOrR/IZrb7QTHzAS9NGCb/lRQmsTlCyqkNGU2//4HeA88zM3SHsqnBGuX1l5OZBfBEQpBb0C3q5nhP+nDi7oceEiOO59HYqb5Iyh29Elu1dpGPDhHJ5k4GTDY8ixLR/ETFOXUeT51e2J8S47iACvzYG8jVXa2P3R/BkmZemwMrg+1XFAAh1tCevx5Tr54CLng97DIZPIpt2MC1ddwVz5c9XHJotnckbrB89Oak6OPhGbpRx1g==" Feb 25 23:55:49 volumio sudo[32049]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-25 23:54' Feb 25 23:55:49 volumio sudo[32049]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 23:55:49 volumio go-librespot[32040]: time="2026-02-25T23:55:49+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 25 23:55:49 volumio go-librespot[32040]: time="2026-02-25T23:55:49+07:00" level=debug msg="completed keyexchange" Feb 25 23:55:49 volumio go-librespot[32040]: time="2026-02-25T23:55:49+07:00" level=debug msg="completed challenge" Feb 25 23:55:49 volumio go-librespot[32040]: time="2026-02-25T23:55:49+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 25 23:55:49 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 23:55:49 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 23:55:49 volumio sudo[32049]: pam_unix(sudo:session): session closed for user root Feb 25 23:55:49 volumio volumio-remote-updater[647]: [2026-02-25 23:55:49] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 25 23:55:49 volumio volumio-remote-updater[647]: [2026-02-25 23:55:49] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 25 23:55:49 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 25 23:55:49 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 25 23:55:49 volumio systemd[1]: volumio.service: Consumed 56.091s CPU time. Feb 25 23:55:49 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 25 23:55:49 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 25 23:55:49 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 8604. Feb 25 23:55:49 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 25 23:55:49 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 25 23:55:49 volumio systemd[1]: volumio.service: Consumed 56.091s CPU time. Feb 25 23:55:49 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 25 23:55:49 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 25 23:55:52 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Feb 25 23:55:52 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 25 23:55:52 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 25 23:55:52 volumio go-librespot[32076]: go-librespot daemon starting... Feb 25 23:55:52 volumio go-librespot[32077]: time="2026-02-25T23:55:52+07:00" level=info msg="running go-librespot 0.4.0" Feb 25 23:55:52 volumio go-librespot[32077]: time="2026-02-25T23:55:52+07:00" level=debug msg="app state loaded" Feb 25 23:55:52 volumio go-librespot[32077]: time="2026-02-25T23:55:52+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 25 23:55:52 volumio go-librespot[32077]: time="2026-02-25T23:55: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-gew1.spotify.com:80]" Feb 25 23:55:52 volumio go-librespot[32077]: time="2026-02-25T23:55:52+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 25 23:55:52 volumio go-librespot[32077]: time="2026-02-25T23:55:52+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 25 23:55:52 volumio go-librespot[32077]: time="2026-02-25T23:55:52+07:00" level=info msg="zeroconf server listening on port 40191" Feb 25 23:55:53 volumio go-librespot[32077]: time="2026-02-25T23:55:53+07:00" level=debug msg="obtained new client token: AADKLCr5fxwkeOc/yEZPOq0Chiz1sFERjfA0ZLJGYMCyjGd2KydwsKMlP4Us0JHSKIM65sfgifCmAHZeGGGTqbDhD51QxjQQelBEjNM6aA5oy7UgymVp2hR915+JQi1ihquTslo3l5mow2AeYET9flod1tc84o7SlondC67SkBYVXo8pAz8pZJ7T799CCopULbITROLn9TRpXAqfcx9I4mmhYmlFRYt27p2Ze34aXg3D7xx7mAOE8Bw=" Feb 25 23:55:53 volumio go-librespot[32077]: time="2026-02-25T23:55:53+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 25 23:55:53 volumio volumio[32061]: info: ------------------------------------------- Feb 25 23:55:53 volumio volumio[32061]: info: ----- Volumio3 ---- Feb 25 23:55:53 volumio volumio[32061]: info: ------------------------------------------- Feb 25 23:55:53 volumio volumio[32061]: info: ----- System startup ---- Feb 25 23:55:53 volumio volumio[32061]: info: ------------------------------------------- Feb 25 23:55:53 volumio go-librespot[32077]: time="2026-02-25T23:55:53+07:00" level=debug msg="completed keyexchange" Feb 25 23:55:53 volumio go-librespot[32077]: time="2026-02-25T23:55:53+07:00" level=debug msg="completed challenge" Feb 25 23:55:53 volumio go-librespot[32077]: time="2026-02-25T23:55:53+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 25 23:55:53 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 23:55:53 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 23:55:54 volumio volumio-remote-updater[647]: [2026-02-25 23:55:54] [connect] Successful connection Feb 25 23:55:54 volumio volumio[32061]: info: MYVOLUMIO Environment detected Feb 25 23:55:54 volumio volumio[32061]: info: Plugin folders cleanup Feb 25 23:55:54 volumio volumio[32061]: info: Scanning into folder /volumio/app/plugins/ Feb 25 23:55:54 volumio volumio[32061]: info: Scanning category audio_interface Feb 25 23:55:54 volumio volumio[32061]: info: Scanning category miscellanea Feb 25 23:55:54 volumio volumio[32061]: info: Scanning category music_service Feb 25 23:55:54 volumio volumio[32061]: info: Scanning category plugins.json Feb 25 23:55:54 volumio volumio[32061]: info: Scanning category system_controller Feb 25 23:55:54 volumio volumio[32061]: info: Scanning category user_interface Feb 25 23:55:54 volumio volumio[32061]: info: Scanning into folder /data/plugins/ Feb 25 23:55:54 volumio volumio[32061]: info: Scanning category music_service Feb 25 23:55:54 volumio volumio[32061]: info: Plugin folders cleanup completed Feb 25 23:55:54 volumio volumio[32061]: info: ------------------------------------------- Feb 25 23:55:54 volumio volumio[32061]: info: ----- Core plugins startup ---- Feb 25 23:55:54 volumio volumio[32061]: info: ------------------------------------------- Feb 25 23:55:54 volumio volumio[32061]: info: Loading plugins from folder /volumio/app/plugins/ Feb 25 23:55:55 volumio volumio[32061]: info: Adding plugin upnp to MyMusic Plugins Feb 25 23:55:55 volumio volumio[32061]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 25 23:55:55 volumio volumio[32061]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 25 23:55:55 volumio volumio[32061]: info: Loading plugins from folder /data/plugins/ Feb 25 23:55:55 volumio volumio[32061]: info: Loading plugin "system"... Feb 25 23:55:55 volumio volumio[32061]: info: Loading plugin "appearance"... Feb 25 23:55:56 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Feb 25 23:55:56 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 25 23:55:56 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 25 23:55:56 volumio go-librespot[32097]: go-librespot daemon starting... Feb 25 23:55:56 volumio go-librespot[32098]: time="2026-02-25T23:55:56+07:00" level=info msg="running go-librespot 0.4.0" Feb 25 23:55:56 volumio go-librespot[32098]: time="2026-02-25T23:55:56+07:00" level=debug msg="app state loaded" Feb 25 23:55:56 volumio go-librespot[32098]: time="2026-02-25T23:55:56+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 25 23:55:56 volumio volumio[32061]: info: Loading plugin "network"... Feb 25 23:55:57 volumio volumio[32061]: info: Refreshing Cached IP Addresses Feb 25 23:55:57 volumio sudo[32106]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 25 23:55:57 volumio sudo[32106]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 23:55:57 volumio sudo[32106]: pam_unix(sudo:session): session closed for user root Feb 25 23:55:57 volumio volumio[32061]: info: Loading plugin "services"... Feb 25 23:55:57 volumio volumio[32061]: info: Loading plugin "alsa_controller"... Feb 25 23:55:57 volumio sudo[32108]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 25 23:55:57 volumio sudo[32108]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 23:55:57 volumio sudo[32108]: pam_unix(sudo:session): session closed for user root Feb 25 23:55:57 volumio sudo[32119]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 25 23:55:57 volumio sudo[32119]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 23:55:57 volumio go-librespot[32098]: time="2026-02-25T23:55:57+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 25 23:55:57 volumio go-librespot[32098]: time="2026-02-25T23:55:57+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 25 23:55:57 volumio go-librespot[32098]: time="2026-02-25T23:55:57+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 25 23:55:57 volumio go-librespot[32098]: time="2026-02-25T23:55:57+07:00" level=info msg="zeroconf server listening on port 38745" Feb 25 23:55:57 volumio volumio[32061]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 25 23:55:57 volumio volumio[32061]: info: Loading plugin "wizard"... Feb 25 23:55:57 volumio volumio[32061]: info: Loading plugin "networkfs"... Feb 25 23:55:57 volumio volumio[32061]: info: Starting Udev Watcher for removable devices Feb 25 23:55:57 volumio volumio[32061]: info: Ignoring mount for partition: boot Feb 25 23:55:57 volumio volumio[32061]: info: Ignoring mount for partition: volumio Feb 25 23:55:57 volumio volumio[32061]: info: Ignoring mount for partition: volumio_data Feb 25 23:55:57 volumio volumio[32061]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 25 23:55:57 volumio volumio[32061]: info: Loading plugin "volumio_command_line_client"... Feb 25 23:55:57 volumio volumio[32061]: info: Loading plugin "upnp"... Feb 25 23:55:57 volumio volumio[32061]: info: [1772038557477] Starting Upmpd Daemon Feb 25 23:55:57 volumio volumio[32061]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 25 23:55:57 volumio volumio[32061]: info: Loading plugin "my_music"... Feb 25 23:55:57 volumio volumio[32061]: info: Loading plugin "mpd"... Feb 25 23:55:57 volumio go-librespot[32098]: time="2026-02-25T23:55:57+07:00" level=debug msg="obtained new client token: AAB2EIgoJJJk4ZflvC77L1nCTvDI+766BfTnW719SIeS9T+Yj4ofDMGRqSVfl04Tj409eVpfULgo55utqPZ3MftW78qioVvY0ajibmV+fZ1dMbXjSY4lyZ1hF498+bFX6fEacuPTVi8mfPPKeUOH79sNIvTQpGMjKComoZ+d+jhkElyb3/wYOpfn733Wc6aJtwllU2nq8rfafFiPq/eZS7A8am1YdrPBu68COu5oI1dehSr6c7/GnlkNWQ==" Feb 25 23:55:57 volumio go-librespot[32098]: time="2026-02-25T23:55:57+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 25 23:55:57 volumio go-librespot[32098]: time="2026-02-25T23:55:57+07:00" level=debug msg="completed keyexchange" Feb 25 23:55:57 volumio go-librespot[32098]: time="2026-02-25T23:55:57+07:00" level=debug msg="completed challenge" Feb 25 23:55:57 volumio go-librespot[32098]: time="2026-02-25T23:55:57+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 25 23:55:57 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 23:55:57 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 23:55:58 volumio volumio[32061]: info: Loading plugin "upnp_browser"... Feb 25 23:55:59 volumio sudo[32119]: pam_unix(sudo:session): session closed for user root Feb 25 23:56:01 volumio volumio[32061]: info: Starting UPNP Browser Feb 25 23:56:01 volumio volumio[32061]: info: Loading plugin "alarm-clock"... Feb 25 23:56:01 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Feb 25 23:56:01 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 25 23:56:01 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 25 23:56:01 volumio go-librespot[32139]: go-librespot daemon starting... Feb 25 23:56:01 volumio go-librespot[32140]: time="2026-02-25T23:56:01+07:00" level=info msg="running go-librespot 0.4.0" Feb 25 23:56:01 volumio go-librespot[32140]: time="2026-02-25T23:56:01+07:00" level=debug msg="app state loaded" Feb 25 23:56:01 volumio go-librespot[32140]: time="2026-02-25T23:56:01+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 25 23:56:01 volumio volumio[32061]: info: Loading plugin "airplay_emulation"... Feb 25 23:56:01 volumio volumio[32061]: info: Starting Shairport Sync Feb 25 23:56:01 volumio volumio[32061]: info: Loading plugin "last_100"... Feb 25 23:56:01 volumio volumio[32061]: info: Loading plugin "webradio"... Feb 25 23:56:01 volumio volumio[32061]: info: Loading plugin "i2s_dacs"... Feb 25 23:56:01 volumio volumio[32061]: info: Loading plugin "volumiodiscovery"... Feb 25 23:56:01 volumio go-librespot[32140]: time="2026-02-25T23:56:01+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 25 23:56:01 volumio go-librespot[32140]: time="2026-02-25T23:56:01+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 25 23:56:01 volumio go-librespot[32140]: time="2026-02-25T23:56:01+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 25 23:56:01 volumio volumio[32061]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 25 23:56:01 volumio volumio[32061]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 25 23:56:01 volumio volumio[32061]: *** WARNING *** For more information see Feb 25 23:56:01 volumio volumio[32061]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 25 23:56:01 volumio volumio[32061]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 25 23:56:01 volumio volumio[32061]: *** WARNING *** For more information see Feb 25 23:56:01 volumio node[32061]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 25 23:56:01 volumio node[32061]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 25 23:56:01 volumio node[32061]: *** WARNING *** For more information see Feb 25 23:56:01 volumio node[32061]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 25 23:56:01 volumio node[32061]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 25 23:56:01 volumio node[32061]: *** WARNING *** For more information see Feb 25 23:56:01 volumio volumio[32061]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 25 23:56:01 volumio go-librespot[32140]: time="2026-02-25T23:56:01+07:00" level=info msg="zeroconf server listening on port 34795" Feb 25 23:56:01 volumio volumio[32061]: info: Discovery: Started advertising with name: Volumio Feb 25 23:56:01 volumio volumio[32061]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 25 23:56:01 volumio volumio[32061]: info: Loading plugin "spop"... Feb 25 23:56:02 volumio go-librespot[32140]: time="2026-02-25T23:56:02+07:00" level=debug msg="obtained new client token: AAD5MalQlYTjv8iuOTtiZeSyPUutfd4BwN9pjbRE8N2o63kQv0xszRZOV2C8ceCgEK5vyoiiXzH+wPSKX3e4BegmfhQkxJEe+2oLAMmJZPTXUsrDB/XxyS+ZZvp3oOZv0oztJC5Vd2+AeKeyJRWrMRp9QQGUGoDo0khWdC2SDH2r7M4JlGjjlQ+dXLAITggZZtRIz2uhSdiVjLVpw/Pznach5WAHq5vQ61sSaaxyP4FDLKm+eEFfzgZinA==" Feb 25 23:56:02 volumio go-librespot[32140]: time="2026-02-25T23:56:02+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 25 23:56:02 volumio go-librespot[32140]: time="2026-02-25T23:56:02+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 25 23:56:02 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 23:56:02 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 23:56:03 volumio volumio[32061]: info: Loading plugin "ytcr"... Feb 25 23:56:05 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Feb 25 23:56:05 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 25 23:56:05 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 25 23:56:05 volumio go-librespot[32155]: go-librespot daemon starting... Feb 25 23:56:05 volumio go-librespot[32156]: time="2026-02-25T23:56:05+07:00" level=info msg="running go-librespot 0.4.0" Feb 25 23:56:05 volumio go-librespot[32156]: time="2026-02-25T23:56:05+07:00" level=debug msg="app state loaded" Feb 25 23:56:05 volumio go-librespot[32156]: time="2026-02-25T23:56:05+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 25 23:56:06 volumio go-librespot[32156]: time="2026-02-25T23:56:06+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 25 23:56:06 volumio go-librespot[32156]: time="2026-02-25T23:56:06+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 25 23:56:06 volumio go-librespot[32156]: time="2026-02-25T23:56:06+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 25 23:56:06 volumio go-librespot[32156]: time="2026-02-25T23:56:06+07:00" level=info msg="zeroconf server listening on port 35107" Feb 25 23:56:06 volumio go-librespot[32156]: time="2026-02-25T23:56:06+07:00" level=debug msg="obtained new client token: AAC97bzQr//oAhuVWmfKc5V/5ZTzW4GQ9ZNNEOHA4q7/N85etxzxkO5g5W8uzuipUrHiqDwNPJs7dVNzlF7sSpON2abxEgGKOGci7uhLHYksJglwtxoTDf7spOn/0vRgbyxxS9Qmv0/GSLEUl5KmhNDR8WLkeH5tuzte2ppJrNc4+xrmZYZU/14ToeiV6QBaVt9zSvMVIl0MsDStTotD6qd3h5K/y23NfCvcY3wDRaq5dBf+GEUw5ZvC+A==" Feb 25 23:56:06 volumio go-librespot[32156]: time="2026-02-25T23:56:06+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 25 23:56:06 volumio volumio[32061]: info: Loading plugin "ytmusic"... Feb 25 23:56:06 volumio go-librespot[32156]: time="2026-02-25T23:56:06+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 25 23:56:06 volumio go-librespot[32156]: time="2026-02-25T23:56:06+07:00" level=debug msg="completed keyexchange" Feb 25 23:56:06 volumio go-librespot[32156]: time="2026-02-25T23:56:06+07:00" level=debug msg="completed challenge" Feb 25 23:56:06 volumio go-librespot[32156]: time="2026-02-25T23:56:06+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 25 23:56:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 23:56:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 23:56:07 volumio volumio-remote-updater[647]: [2026-02-25 23:56:07] [connect] Successful connection Feb 25 23:56:07 volumio volumio[32061]: info: Loading plugin "outputs"... Feb 25 23:56:07 volumio volumio[32061]: info: Loading plugin "albumart"... Feb 25 23:56:07 volumio volumio[32061]: info: Plugin example_plugin is not enabled Feb 25 23:56:07 volumio volumio[32061]: info: Loading plugin "inputs"... Feb 25 23:56:07 volumio volumio[32061]: info: Loading plugin "updater_comm"... Feb 25 23:56:07 volumio volumio[32061]: info: Plugin mpdemulation is not enabled Feb 25 23:56:07 volumio volumio[32061]: info: Loading plugin "rest_api"... Feb 25 23:56:08 volumio volumio[32061]: info: Loading plugin "websocket"... Feb 25 23:56:08 volumio volumio[32061]: info: Starting Socket.io Server version 1.7.4 Feb 25 23:56:08 volumio volumio[32061]: info: Loading plugin "RoonBridge"... Feb 25 23:56:08 volumio volumio[32061]: info: Applying required configuration parameters for plugin RoonBridge Feb 25 23:56:08 volumio volumio[32061]: info: Loading i18n strings for locale en Feb 25 23:56:08 volumio volumio[32061]: Updating browse sources language Feb 25 23:56:08 volumio volumio[32061]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 25 23:56:08 volumio volumio[32177]: Forking 3 albumart workers Feb 25 23:56:08 volumio volumio[32061]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 25 23:56:08 volumio volumio[32061]: info: CoreCommandRouter::initPlayerControls Feb 25 23:56:08 volumio volumio[32061]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 23:56:08 volumio volumio[32061]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 23:56:08 volumio volumio[32061]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 23:56:08 volumio volumio[32061]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 23:56:08 volumio volumio[32061]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 23:56:09 volumio volumio[32061]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 23:56:09 volumio volumio[32061]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 23:56:09 volumio volumio[32061]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 23:56:09 volumio volumio[32061]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 25 23:56:09 volumio volumio[32061]: Express server listening on port 3000 Feb 25 23:56:09 volumio volumio[32061]: [Metrics] WebUI: 16s 612.32ms Feb 25 23:56:09 volumio volumio[32061]: info: CoreStateMachine::resetVolumioState Feb 25 23:56:09 volumio volumio[32061]: info: CoreStateMachine::getcurrentVolume Feb 25 23:56:09 volumio volumio[32061]: info: CoreCommandRouter::volumioRetrievevolume Feb 25 23:56:09 volumio sudo[32222]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 25 23:56:09 volumio sudo[32222]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 23:56:09 volumio sudo[32222]: pam_unix(sudo:session): session closed for user root Feb 25 23:56:09 volumio sudo[32224]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 25 23:56:09 volumio sudo[32224]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 23:56:09 volumio sudo[32224]: pam_unix(sudo:session): session closed for user root Feb 25 23:56:09 volumio volumio[32061]: info: Volumio Network Manager: Network status updated: 1 Feb 25 23:56:09 volumio volumio[32061]: info: VolumeController:: Volume=100 Mute =false Feb 25 23:56:09 volumio volumio[32061]: info: CoreStateMachine::pushState Feb 25 23:56:09 volumio volumio[32061]: info: CorePlayQueue::getTrack 0 Feb 25 23:56:09 volumio volumio[32061]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 25 23:56:09 volumio volumio[32061]: info: CoreCommandRouter::volumioPushState Feb 25 23:56:09 volumio volumio[32061]: info: CoreStateMachine::updateTrackBlock Feb 25 23:56:09 volumio volumio[32061]: info: CorePlayQueue::getTrackBlock Feb 25 23:56:09 volumio volumio[32061]: info: CoreCommandRouter::volumioRetrievevolume Feb 25 23:56:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Feb 25 23:56:09 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 25 23:56:09 volumio volumio-remote-updater[647]: [2026-02-25 23:56:09] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1772038567 101 Feb 25 23:56:09 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 25 23:56:09 volumio volumio[32061]: 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 25 23:56:09 volumio go-librespot[32230]: go-librespot daemon starting... Feb 25 23:56:09 volumio volumio[32061]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 25 23:56:10 volumio volumio[32061]: info: Reloading queue from file Feb 25 23:56:10 volumio go-librespot[32231]: time="2026-02-25T23:56:10+07:00" level=info msg="running go-librespot 0.4.0" Feb 25 23:56:10 volumio go-librespot[32231]: time="2026-02-25T23:56:10+07:00" level=debug msg="app state loaded" Feb 25 23:56:10 volumio go-librespot[32231]: time="2026-02-25T23:56:10+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 25 23:56:10 volumio volumio[32061]: info: CoreStateMachine::setRepeat null single undefined Feb 25 23:56:10 volumio volumio[32061]: info: CoreStateMachine::pushState Feb 25 23:56:10 volumio volumio[32061]: info: CorePlayQueue::getTrack 0 Feb 25 23:56:10 volumio volumio[32061]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 25 23:56:10 volumio volumio[32061]: info: CoreCommandRouter::volumioPushState Feb 25 23:56:10 volumio volumio[32061]: info: CoreStateMachine::setRandom null Feb 25 23:56:10 volumio volumio[32061]: info: CoreStateMachine::pushState Feb 25 23:56:10 volumio volumio[32061]: info: CorePlayQueue::getTrack 0 Feb 25 23:56:10 volumio volumio[32061]: info: CoreCommandRouter::volumioPushState Feb 25 23:56:10 volumio volumio[32061]: info: Setting Device type: Raspberry PI Feb 25 23:56:10 volumio volumio[32061]: info: Completed loading Core Plugins Feb 25 23:56:10 volumio volumio[32061]: info: Preparing to generate the ALSA configuration file Feb 25 23:56:10 volumio volumio[32061]: info: VolumeController:: Volume=100 Mute =false Feb 25 23:56:10 volumio volumio[32061]: info: CoreStateMachine::pushState Feb 25 23:56:10 volumio volumio[32061]: info: CorePlayQueue::getTrack 0 Feb 25 23:56:10 volumio volumio[32061]: info: CoreCommandRouter::volumioPushState Feb 25 23:56:10 volumio volumio[32061]: info: Asound.conf file unchanged, so no further update is needed Feb 25 23:56:10 volumio volumio[32061]: info: Output device has changed, restarting MPD Feb 25 23:56:10 volumio go-librespot[32231]: time="2026-02-25T23:56:10+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 25 23:56:10 volumio go-librespot[32231]: time="2026-02-25T23:56:10+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 25 23:56:10 volumio go-librespot[32231]: time="2026-02-25T23:56:10+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 25 23:56:10 volumio sudo[32246]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 25 23:56:10 volumio sudo[32246]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 23:56:10 volumio sudo[32248]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 25 23:56:10 volumio sudo[32248]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 23:56:10 volumio volumio[32061]: info: Output device has changed, restarting Shairport Sync Feb 25 23:56:10 volumio volumio[32061]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 23:56:10 volumio volumio[32061]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 25 23:56:10 volumio go-librespot[32231]: time="2026-02-25T23:56:10+07:00" level=info msg="zeroconf server listening on port 39435" Feb 25 23:56:10 volumio sudo[32248]: pam_unix(sudo:session): session closed for user root Feb 25 23:56:10 volumio sudo[32250]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 25 23:56:10 volumio sudo[32250]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 23:56:10 volumio volumio[32061]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 25 23:56:10 volumio volumio[32061]: info: ___________ START PLUGINS ___________ Feb 25 23:56:11 volumio volumio[32061]: info: ControllerMpd::onStart: Initializing MPD Feb 25 23:56:11 volumio volumio[32061]: info: Creating MPD Configuration file Feb 25 23:56:11 volumio go-librespot[32231]: time="2026-02-25T23:56:11+07:00" level=debug msg="obtained new client token: AABLOHgmJfRVdVFe2U15bC98YvteasU5Xo28nRM/veKV7Ez2+YzBXtkXXqd38XZHGbl5s1JcIT9aSF4fIgaroE/M/eWwjkaamBRlxWRuLTtuSsQ7dKzBP6dz+CRA0HXstOIIwxLE72Y83dQeeJeCVcaQki5+NB7yf2BRci0fdqqehz1L6oWwu9NXR0OWpIOrX8Mp5yKSljf+aWoeLAWR2wBmuzP8hv3iTDbF5kcTgdJ5Yi55YReJB2k=" Feb 25 23:56:11 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 25 23:56:11 volumio volumio[32061]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 25 23:56:11 volumio volumio[32061]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 25 23:56:11 volumio volumio[32061]: info: [1772038571150] CoreMusicLibrary::Adding element Media Servers Feb 25 23:56:11 volumio sudo[32246]: pam_unix(sudo:session): session closed for user root Feb 25 23:56:11 volumio volumio[32061]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 25 23:56:11 volumio volumio[32061]: info: UPNP Browser: Client initialized successfully Feb 25 23:56:11 volumio go-librespot[32231]: time="2026-02-25T23:56:11+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 25 23:56:11 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 25 23:56:11 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 25 23:56:11 volumio systemd[1]: mpd.service: Consumed 6.964s CPU time. Feb 25 23:56:11 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 25 23:56:11 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 25 23:56:11 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 25 23:56:11 volumio sudo[32261]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 25 23:56:11 volumio sudo[32261]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 23:56:11 volumio sudo[32259]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 25 23:56:11 volumio sudo[32259]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 23:56:11 volumio go-librespot[32231]: time="2026-02-25T23:56:11+07:00" level=debug msg="completed keyexchange" Feb 25 23:56:11 volumio go-librespot[32231]: time="2026-02-25T23:56:11+07:00" level=debug msg="completed challenge" Feb 25 23:56:11 volumio sudo[32259]: pam_unix(sudo:session): session closed for user root Feb 25 23:56:11 volumio volumio[32061]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 23:56:11 volumio volumio[32061]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 25 23:56:11 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 25 23:56:11 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 25 23:56:11 volumio go-librespot[32231]: time="2026-02-25T23:56:11+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 25 23:56:11 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 23:56:11 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 23:56:11 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 25 23:56:11 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 25 23:56:11 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 25 23:56:11 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 25 23:56:11 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 25 23:56:11 volumio volumio[32061]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 25 23:56:11 volumio volumio[32061]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 23:56:11 volumio volumio[32061]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 25 23:56:11 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 25 23:56:11 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 25 23:56:11 volumio volumio[32061]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 25 23:56:11 volumio volumio[32061]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 25 23:56:11 volumio volumio[32061]: info: [1772038571759] CoreMusicLibrary::Adding element Last_100 Feb 25 23:56:11 volumio volumio[32061]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 25 23:56:11 volumio volumio[32061]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 25 23:56:11 volumio volumio[32061]: info: [1772038571778] CoreMusicLibrary::Adding element Webradio Feb 25 23:56:11 volumio volumio[32061]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 25 23:56:11 volumio volumio[32061]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 25 23:56:11 volumio volumio[32061]: info: Initializing BBC Radios Feb 25 23:56:12 volumio volumio[32061]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 25 23:56:12 volumio volumio[32061]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 25 23:56:12 volumio sudo[32274]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 25 23:56:12 volumio sudo[32274]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 25 23:56:12 volumio sudo[32274]: pam_unix(sudo:session): session closed for user root Feb 25 23:56:12 volumio volumio[32061]: info: Creating Spotify config file Feb 25 23:56:12 volumio volumio[32061]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 23:56:13 volumio volumio[32187]: Starting albumart workers Feb 25 23:56:13 volumio volumio[32188]: Starting albumart workers Feb 25 23:56:13 volumio volumio[32189]: Starting albumart workers Feb 25 23:56:13 volumio volumio[32061]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 25 23:56:13 volumio volumio[32061]: info: [1772038573633] CoreMusicLibrary::Adding element YouTube Music Feb 25 23:56:13 volumio volumio[32061]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 25 23:56:13 volumio volumio[32061]: Cannot find translation for source YouTube Music Feb 25 23:56:13 volumio volumio[32061]: info: Volumio Calling Home Feb 25 23:56:13 volumio sudo[32294]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 25 23:56:13 volumio sudo[32294]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 23:56:14 volumio sudo[32294]: pam_unix(sudo:session): session closed for user root Feb 25 23:56:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Feb 25 23:56:14 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 25 23:56:14 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 25 23:56:14 volumio go-librespot[32299]: go-librespot daemon starting... Feb 25 23:56:14 volumio go-librespot[32300]: time="2026-02-25T23:56:14+07:00" level=info msg="running go-librespot 0.4.0" Feb 25 23:56:15 volumio volumio[32061]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 25 23:56:15 volumio volumio[32061]: info: Discovery: Found device Volumio Feb 25 23:56:15 volumio volumio[32061]: info: CoreCommandRouter::volumioGetState Feb 25 23:56:15 volumio volumio[32061]: info: CorePlayQueue::getTrack 0 Feb 25 23:56:15 volumio volumio[32061]: info: MPD Permissions set Feb 25 23:56:15 volumio volumio[32061]: info: MPD Permissions set Feb 25 23:56:15 volumio volumio[32061]: info: Upmpdcli Daemon Started Feb 25 23:56:15 volumio volumio[32061]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 25 23:56:15 volumio volumio[32061]: info: Discovery: Found device Volumio Feb 25 23:56:15 volumio volumio[32061]: info: CoreCommandRouter::volumioGetState Feb 25 23:56:15 volumio volumio[32061]: info: CorePlayQueue::getTrack 0 Feb 25 23:56:15 volumio volumio[32061]: info: Spotify config file written Feb 25 23:56:15 volumio go-librespot[32300]: time="2026-02-25T23:56:15+07:00" level=info msg="zeroconf server listening on port 36179" Feb 25 23:56:15 volumio volumio[32061]: 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 25 23:56:15 volumio volumio[32061]: info: Volumio called home Feb 25 23:56:15 volumio volumio[32061]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 23:56:15 volumio volumio[32061]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 23:56:15 volumio volumio[32061]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 23:56:15 volumio volumio[32061]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 23:56:15 volumio volumio[32061]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 23:56:15 volumio volumio[32061]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 23:56:15 volumio volumio[32061]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 23:56:15 volumio volumio[32061]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 23:56:15 volumio sudo[32308]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 25 23:56:15 volumio sudo[32308]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 23:56:15 volumio volumio[32061]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 25 23:56:15 volumio volumio[32061]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 23:56:15 volumio volumio[32061]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 23:56:15 volumio volumio[32061]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 23:56:15 volumio volumio[32061]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 23:56:15 volumio volumio[32061]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 23:56:15 volumio volumio[32061]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 23:56:15 volumio volumio[32061]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 23:56:15 volumio volumio[32061]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 23:56:15 volumio volumio[32061]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 23:56:15 volumio volumio[32061]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 25 23:56:15 volumio volumio[32061]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 25 23:56:15 volumio volumio[32061]: info: No need to fix Spotify hosts Feb 25 23:56:15 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 25 23:56:15 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 25 23:56:15 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 25 23:56:15 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 25 23:56:15 volumio go-librespot[32320]: go-librespot daemon starting... Feb 25 23:56:15 volumio sudo[32308]: pam_unix(sudo:session): session closed for user root Feb 25 23:56:16 volumio go-librespot[32321]: time="2026-02-25T23:56:16+07:00" level=info msg="running go-librespot 0.4.0" Feb 25 23:56:16 volumio go-librespot[32321]: time="2026-02-25T23:56:16+07:00" level=debug msg="app state loaded" Feb 25 23:56:16 volumio go-librespot[32321]: time="2026-02-25T23:56:16+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 25 23:56:16 volumio go-librespot[32321]: time="2026-02-25T23:56: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-gew4.spotify.com:80]" Feb 25 23:56:16 volumio go-librespot[32321]: time="2026-02-25T23:56:16+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 25 23:56:16 volumio go-librespot[32321]: time="2026-02-25T23:56:16+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 25 23:56:16 volumio go-librespot[32321]: time="2026-02-25T23:56:16+07:00" level=info msg="zeroconf server listening on port 44991" Feb 25 23:56:16 volumio go-librespot[32321]: time="2026-02-25T23:56:16+07:00" level=debug msg="obtained new client token: AADk8Y7bwZorWsqtQZSF+5UvgeW3zf0zdW4lKUN7Es12gUpsvtlarzm0YoFoXPlgHwnOnU36F2OObHhBlZNd5roPyoshed++N9H6gDBTJFmJr/LjWznkRj+lycZVrjcGdaJmkSvkciey4J+ywhCkO5fLWon7yxpGnbhqcqMpi+PURlsPhBw9iMwAQRzYZpbPAu5JjX8Mjgg+50JjJ+EBPjwVk+nn4qEq8Siq2dmONRMgqI66CRIUSqoBjA==" Feb 25 23:56:17 volumio go-librespot[32321]: time="2026-02-25T23:56:17+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 25 23:56:17 volumio go-librespot[32321]: time="2026-02-25T23:56:17+07:00" level=debug msg="completed keyexchange" Feb 25 23:56:17 volumio go-librespot[32321]: time="2026-02-25T23:56:17+07:00" level=debug msg="completed challenge" Feb 25 23:56:17 volumio go-librespot[32321]: time="2026-02-25T23:56:17+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 25 23:56:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 23:56:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 23:56:17 volumio volumio[32061]: info: Starting Shairport Sync Feb 25 23:56:17 volumio volumio[32061]: info: Starting Shairport Sync Feb 25 23:56:17 volumio volumio[32061]: info: Starting Shairport Sync Feb 25 23:56:17 volumio sudo[32361]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 25 23:56:17 volumio sudo[32361]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 23:56:17 volumio sudo[32367]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 25 23:56:17 volumio sudo[32367]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 23:56:17 volumio sudo[32363]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 25 23:56:17 volumio sudo[32363]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 23:56:17 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 25 23:56:17 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 25 23:56:17 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 25 23:56:17 volumio systemd[1]: shairport-sync.service: Consumed 2.257s CPU time. Feb 25 23:56:17 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 25 23:56:17 volumio sudo[32361]: pam_unix(sudo:session): session closed for user root Feb 25 23:56:17 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 25 23:56:17 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 25 23:56:17 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 25 23:56:17 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 25 23:56:17 volumio sudo[32367]: pam_unix(sudo:session): session closed for user root Feb 25 23:56:17 volumio sudo[32363]: pam_unix(sudo:session): session closed for user root Feb 25 23:56:18 volumio volumio[32061]: info: Shairport-Sync Started Feb 25 23:56:18 volumio volumio[32061]: Error adding Membership: Error: addMembership EINVAL Feb 25 23:56:18 volumio volumio[32061]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 25 23:56:18 volumio volumio[32061]: SPOTIFY: BQDbZDuvp_Dfq588g3VSapm4lkW1H6z_NdpP2DyPdupg9dkbB7sNdtcKzcB3E9d-4sK0TmDVp3hyKrKUfrQZsHRCo1im6lZF5Gozl_rNQwObJiFeztahfNr0pJzn1D2QKO0g2Hmpj7IZdmR0Dq1UuNgBD3XHKhZ0kW62DC9Xn3qUmrwlxcPBpOatMliMPmPlwJEm4X93l0Z2vhaAgC0Ymzv2gV5dgvR6KfB9KcH3Em4EBYAhKCRX-LngEOfP_0LNcbR7BC591TRS_sFdSQRxEzuF_S38iHBsyoBB6xDh5ibYEUNxtBgVRhQF Feb 25 23:56:18 volumio volumio[32061]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 25 23:56:18 volumio volumio[32061]: info: New Spotify access token = BQDbZDuvp_Dfq588g3VSapm4lkW1H6z_NdpP2DyPdupg9dkbB7sNdtcKzcB3E9d-4sK0TmDVp3hyKrKUfrQZsHRCo1im6lZF5Gozl_rNQwObJiFeztahfNr0pJzn1D2QKO0g2Hmpj7IZdmR0Dq1UuNgBD3XHKhZ0kW62DC9Xn3qUmrwlxcPBpOatMliMPmPlwJEm4X93l0Z2vhaAgC0Ymzv2gV5dgvR6KfB9KcH3Em4EBYAhKCRX-LngEOfP_0LNcbR7BC591TRS_sFdSQRxEzuF_S38iHBsyoBB6xDh5ibYEUNxtBgVRhQF Feb 25 23:56:18 volumio volumio[32061]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 25 23:56:18 volumio volumio[32061]: info: Shairport-Sync Started Feb 25 23:56:18 volumio volumio[32061]: info: Shairport-Sync Started Feb 25 23:56:18 volumio volumio[32061]: info: CoreCommandRouter::volumioGetState Feb 25 23:56:18 volumio volumio[32061]: info: CorePlayQueue::getTrack 0 Feb 25 23:56:18 volumio volumio[32061]: 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 25 23:56:18 volumio volumio[32061]: info: Spotify Successfully logged in Feb 25 23:56:18 volumio volumio[32061]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 25 23:56:18 volumio volumio[32061]: info: [1772038578773] CoreMusicLibrary::Adding element Spotify Feb 25 23:56:18 volumio volumio[32061]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 25 23:56:18 volumio volumio[32061]: Cannot find translation for source YouTube Music Feb 25 23:56:18 volumio volumio[32061]: Cannot find translation for source Spotify Feb 25 23:56:19 volumio mpd[32291]: 2026-02-25T23:56:19 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 25 23:56:19 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 25 23:56:19 volumio sudo[32250]: pam_unix(sudo:session): session closed for user root Feb 25 23:56:19 volumio sudo[32261]: pam_unix(sudo:session): session closed for user root Feb 25 23:56:19 volumio volumio[32061]: error: MPD error: The expression evaluated to a falsy value: Feb 25 23:56:19 volumio volumio[32061]: assert.ok(self.idling) Feb 25 23:56:19 volumio volumio[32061]: error: The expression evaluated to a falsy value: Feb 25 23:56:19 volumio volumio[32061]: assert.ok(self.idling) Feb 25 23:56:19 volumio volumio[32061]: info: MPD running with PID32291 Feb 25 23:56:19 volumio volumio[32061]: ,establishing connection Feb 25 23:56:19 volumio volumio[32061]: error: updateQueue error: null Feb 25 23:56:19 volumio volumio[32061]: error: updateQueue error: null Feb 25 23:56:19 volumio volumio[32061]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 25 23:56:19 volumio volumio[32061]: info: CoreCommandRouter::volumioRetrievevolume Feb 25 23:56:19 volumio volumio[32061]: info: VolumeController:: Volume=100 Mute =false Feb 25 23:56:19 volumio volumio[32061]: info: CoreCommandRouter::volumioGetState Feb 25 23:56:19 volumio volumio[32061]: info: CorePlayQueue::getTrack 0 Feb 25 23:56:19 volumio volumio[32061]: info: CoreStateMachine::pushState Feb 25 23:56:19 volumio volumio[32061]: info: CorePlayQueue::getTrack 0 Feb 25 23:56:19 volumio volumio[32061]: info: CoreCommandRouter::volumioPushState Feb 25 23:56:20 volumio volumio[32061]: info: Completed starting Core Plugins Feb 25 23:56:20 volumio volumio[32061]: info: ------------------------------------------- Feb 25 23:56:20 volumio volumio[32061]: info: ----- MyVolumio plugins startup ---- Feb 25 23:56:20 volumio volumio[32061]: info: ------------------------------------------- Feb 25 23:56:20 volumio volumio[32061]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 25 23:56:20 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 25 23:56:20 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 25 23:56:20 volumio volumio[32061]: info: go-librespot daemon successfully initialized Feb 25 23:56:20 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 25 23:56:20 volumio go-librespot[32393]: go-librespot daemon starting... Feb 25 23:56:20 volumio go-librespot[32394]: time="2026-02-25T23:56:20+07:00" level=info msg="running go-librespot 0.4.0" Feb 25 23:56:20 volumio go-librespot[32394]: time="2026-02-25T23:56:20+07:00" level=debug msg="app state loaded" Feb 25 23:56:20 volumio go-librespot[32394]: time="2026-02-25T23:56:20+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 25 23:56:21 volumio go-librespot[32394]: time="2026-02-25T23:56:21+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 25 23:56:21 volumio go-librespot[32394]: time="2026-02-25T23:56:21+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 25 23:56:21 volumio go-librespot[32394]: time="2026-02-25T23:56:21+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 25 23:56:21 volumio go-librespot[32394]: time="2026-02-25T23:56:21+07:00" level=info msg="zeroconf server listening on port 45549" Feb 25 23:56:21 volumio go-librespot[32394]: time="2026-02-25T23:56:21+07:00" level=debug msg="obtained new client token: AABkAnHtv92owVkBANTHsyecE2aILqYpbDlFKnT0iULLKXLAq0Db0impCa092V2rxBseIu39wVVaFmQjBbBrUczQ6x2EeYY73QmwkkYWgfJCzBF9N0xXGJyHSG3uAgr7u8TVBeSl3AG+T9jIUQy/+6C8VyGGh/41ZMaEWHBxyrRz0UgekQ3hFELKVc6GRrDg0/FbfHRG83CEfQtBAcpqGMb7jjKjRLBiEeUcybOO7ybPxJ1F4s4js5E=" Feb 25 23:56:21 volumio go-librespot[32394]: time="2026-02-25T23:56:21+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 25 23:56:21 volumio go-librespot[32394]: time="2026-02-25T23:56:21+07:00" level=debug msg="completed keyexchange" Feb 25 23:56:21 volumio go-librespot[32394]: time="2026-02-25T23:56:21+07:00" level=debug msg="completed challenge" Feb 25 23:56:21 volumio go-librespot[32394]: time="2026-02-25T23:56: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 25 23:56:21 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 23:56:21 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 23:56:23 volumio volumio[32061]: info: Initializing connection to go-librespot Websocket Feb 25 23:56:23 volumio volumio[32061]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 25 23:56:24 volumio volumio[32061]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 25 23:56:24 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 25 23:56:24 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 25 23:56:24 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 25 23:56:24 volumio go-librespot[32401]: go-librespot daemon starting... Feb 25 23:56:24 volumio go-librespot[32402]: time="2026-02-25T23:56:24+07:00" level=info msg="running go-librespot 0.4.0" Feb 25 23:56:24 volumio go-librespot[32402]: time="2026-02-25T23:56:24+07:00" level=debug msg="app state loaded" Feb 25 23:56:24 volumio go-librespot[32402]: time="2026-02-25T23:56:24+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 25 23:56:25 volumio go-librespot[32402]: time="2026-02-25T23:56: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-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 25 23:56:25 volumio go-librespot[32402]: time="2026-02-25T23:56:25+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 25 23:56:25 volumio go-librespot[32402]: time="2026-02-25T23:56:25+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 25 23:56:25 volumio go-librespot[32402]: time="2026-02-25T23:56:25+07:00" level=info msg="zeroconf server listening on port 36433" Feb 25 23:56:25 volumio go-librespot[32402]: time="2026-02-25T23:56:25+07:00" level=debug msg="obtained new client token: AAAIM6PgxdDrQyNq2RHxLLESq/XSuIqbhOwGqXd1RDy0TmAssBn58VYLZhp4JapixIhrwAqBbSACFZykvntCPhzmF5rLfno8OYb6Zg5M5wuoWmdBrLz6hCG8kR6cic+WTamzAtMR8bGoRe+rbIDqluSC6cSnzH9SXUFDipQ4uaXaWsCoGNv9k1ggUxcBhhtTNRVuJzTV51NdBxHjaCWDJPtmEI0ZxvhFY5NW42B6B6xKx4jVgpRqX76geg==" Feb 25 23:56:25 volumio go-librespot[32402]: time="2026-02-25T23:56:25+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 25 23:56:25 volumio go-librespot[32402]: time="2026-02-25T23:56:25+07:00" level=debug msg="completed keyexchange" Feb 25 23:56:25 volumio go-librespot[32402]: time="2026-02-25T23:56:25+07:00" level=debug msg="completed challenge" Feb 25 23:56:25 volumio go-librespot[32402]: time="2026-02-25T23:56: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 25 23:56:25 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 23:56:25 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 23:56:26 volumio volumio[32061]: info: Initializing connection to go-librespot Websocket Feb 25 23:56:26 volumio volumio[32061]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 25 23:56:29 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 25 23:56:29 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 25 23:56:29 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 25 23:56:29 volumio go-librespot[32423]: go-librespot daemon starting... Feb 25 23:56:29 volumio go-librespot[32424]: time="2026-02-25T23:56:29+07:00" level=info msg="running go-librespot 0.4.0" Feb 25 23:56:29 volumio go-librespot[32424]: time="2026-02-25T23:56:29+07:00" level=debug msg="app state loaded" Feb 25 23:56:29 volumio go-librespot[32424]: time="2026-02-25T23:56:29+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 25 23:56:29 volumio volumio[32061]: info: Initializing connection to go-librespot Websocket Feb 25 23:56:29 volumio go-librespot[32424]: time="2026-02-25T23:56:29+07:00" level=debug msg="new websocket client" Feb 25 23:56:29 volumio volumio[32061]: info: Connection to go-librespot Websocket established Feb 25 23:56:29 volumio volumio[32061]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 25 23:56:29 volumio volumio[32061]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 25 23:56:29 volumio volumio[32061]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 25 23:56:29 volumio volumio[32061]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 25 23:56:29 volumio volumio[32061]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 25 23:56:29 volumio volumio[32061]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 25 23:56:29 volumio volumio[32061]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 25 23:56:29 volumio volumio[32061]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 25 23:56:29 volumio volumio[32061]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 25 23:56:29 volumio volumio[32061]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 25 23:56:29 volumio volumio[32061]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 25 23:56:29 volumio volumio[32061]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 25 23:56:29 volumio volumio[32061]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 25 23:56:29 volumio volumio[32061]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 25 23:56:29 volumio volumio[32061]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 25 23:56:29 volumio volumio[32061]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 25 23:56:29 volumio volumio[32061]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 25 23:56:29 volumio volumio[32061]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 25 23:56:29 volumio volumio[32061]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 25 23:56:29 volumio volumio[32061]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 25 23:56:29 volumio volumio[32061]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 25 23:56:29 volumio volumio[32061]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 25 23:56:29 volumio volumio[32061]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 25 23:56:29 volumio volumio[32061]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 25 23:56:29 volumio volumio[32061]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 25 23:56:29 volumio volumio[32061]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 25 23:56:29 volumio volumio[32061]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 25 23:56:29 volumio volumio[32061]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 25 23:56:29 volumio volumio[32061]: info: Adding plugin bluetooth to MyMusic Plugins Feb 25 23:56:29 volumio volumio[32061]: info: Adding plugin multiroom to MyMusic Plugins Feb 25 23:56:29 volumio volumio[32061]: info: Adding plugin metavolumio to MyMusic Plugins Feb 25 23:56:29 volumio volumio[32061]: info: Adding plugin cd_controller to MyMusic Plugins Feb 25 23:56:29 volumio volumio[32061]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 25 23:56:29 volumio volumio[32061]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 25 23:56:29 volumio volumio[32061]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 25 23:56:29 volumio volumio[32061]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 25 23:56:29 volumio go-librespot[32424]: time="2026-02-25T23:56: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 25 23:56:29 volumio go-librespot[32424]: time="2026-02-25T23:56: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 25 23:56:29 volumio go-librespot[32424]: time="2026-02-25T23:56: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 25 23:56:29 volumio go-librespot[32424]: time="2026-02-25T23:56:29+07:00" level=info msg="zeroconf server listening on port 43573" Feb 25 23:56:29 volumio go-librespot[32424]: time="2026-02-25T23:56:29+07:00" level=debug msg="obtained new client token: AABL6sw0dCN4t6LO4ohxl3qALe75btGjWHN/PQD68plckYkMp99CnnqekFc5hLr4uEdnGpIyuShMwOuYp81Lq2U56pWb2JqYwHa0JfwR8ZYa91P1XFEoumyKvfKCG1gXokT1KA7/06XZVQnlRfb8FHSKmz0nxNggJ1FGUS29x1jUlZvCgA9vvN2+DJGMQPLxlIY8lzkcnodfjyvI8dZX548PxVGgjFK+qyVKoAwPolw/eMRDyghoFthrVw==" Feb 25 23:56:30 volumio go-librespot[32424]: time="2026-02-25T23:56:30+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 25 23:56:30 volumio go-librespot[32424]: time="2026-02-25T23:56:30+07:00" level=debug msg="completed keyexchange" Feb 25 23:56:30 volumio go-librespot[32424]: time="2026-02-25T23:56:30+07:00" level=debug msg="completed challenge" Feb 25 23:56:30 volumio go-librespot[32424]: time="2026-02-25T23:56: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 25 23:56:30 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 23:56:30 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 23:56:31 volumio volumio[32061]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 25 23:56:31 volumio volumio[32061]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 25 23:56:31 volumio volumio[32061]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 25 23:56:31 volumio volumio[32061]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 25 23:56:31 volumio volumio[32061]: info: Starting MyVolumio Remote Streaming Endpoints Feb 25 23:56:31 volumio volumio[32061]: info: MyVolumio login type: Token Feb 25 23:56:31 volumio volumio[32061]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 25 23:56:31 volumio volumio[32061]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 25 23:56:33 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Feb 25 23:56:33 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 25 23:56:33 volumio volumio[32061]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 25 23:56:33 volumio volumio[32061]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 25 23:56:33 volumio volumio[32061]: info: Streaming services startup Feb 25 23:56:33 volumio volumio[32061]: info: Starting Streaming Daemon Feb 25 23:56:33 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 25 23:56:33 volumio go-librespot[32431]: go-librespot daemon starting... Feb 25 23:56:33 volumio sudo[32434]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 25 23:56:33 volumio sudo[32434]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 25 23:56:33 volumio go-librespot[32436]: time="2026-02-25T23:56:33+07:00" level=info msg="running go-librespot 0.4.0" Feb 25 23:56:33 volumio volumio[32061]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 25 23:56:33 volumio go-librespot[32436]: time="2026-02-25T23:56:33+07:00" level=debug msg="app state loaded" Feb 25 23:56:33 volumio go-librespot[32436]: time="2026-02-25T23:56:33+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 25 23:56:33 volumio sudo[32434]: pam_unix(sudo:session): session closed for user root Feb 25 23:56:33 volumio volumio[32061]: info: Getting Spotify volume Feb 25 23:56:33 volumio volumio[32061]: info: Connection to go-librespot Websocket closed Feb 25 23:56:33 volumio volumio[32061]: error: Cannot start Volumio Streaming Daemon Feb 25 23:56:33 volumio volumio[32061]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 25 23:56:33 volumio volumio[32061]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 25 23:56:33 volumio volumio[32061]: 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 25 23:56:33 volumio volumio[32061]: info: CoreCommandRouter::volumioGetState Feb 25 23:56:33 volumio volumio[32061]: info: CorePlayQueue::getTrack 0 Feb 25 23:56:33 volumio volumio[32061]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 25 23:56:33 volumio volumio[32061]: SPOTIFY: SPOTIFY VOLUME undefined Feb 25 23:56:33 volumio volumio[32061]: SPOTIFY: VOLUMIO VOLUME 100 Feb 25 23:56:34 volumio volumio[32061]: info: Aligning Spotify Volume to Volumio Volume Feb 25 23:56:34 volumio volumio[32061]: info: CoreCommandRouter::volumioGetState Feb 25 23:56:34 volumio volumio[32061]: info: CorePlayQueue::getTrack 0 Feb 25 23:56:34 volumio volumio[32061]: info: Setting Spotify Volume from Volumio: 100 Feb 25 23:56:34 volumio go-librespot[32436]: time="2026-02-25T23:56: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 25 23:56:34 volumio go-librespot[32436]: time="2026-02-25T23:56:34+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 25 23:56:34 volumio go-librespot[32436]: time="2026-02-25T23:56:34+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 25 23:56:34 volumio go-librespot[32436]: time="2026-02-25T23:56:34+07:00" level=info msg="zeroconf server listening on port 42613" Feb 25 23:56:34 volumio go-librespot[32436]: time="2026-02-25T23:56:34+07:00" level=debug msg="obtained new client token: AAAFbcHdGH/YVoUp/CY3OWsDICpFjuTEuy/xkEo/gpHRU5ort5VlIu+Jwzsg1zr1QkqexOfTPVk3LgjGDG8z3SNEabhKC1qY/mKU8GNE4EQ8BfwjfIassrLmuEQXxqpdJQZdjLnwc9pVIfDpQoLnz5HyQwGWxPjkH3+BEbBq3An1dmioMSIoMiCR+NUSsusHQTl6qmJgC8ZoocuJt5aljumgeQ2XnuH6icPQoYutL7XkM789TgRDMyg=" Feb 25 23:56:34 volumio go-librespot[32436]: time="2026-02-25T23:56:34+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 25 23:56:34 volumio go-librespot[32436]: time="2026-02-25T23:56:34+07:00" level=debug msg="completed keyexchange" Feb 25 23:56:34 volumio go-librespot[32436]: time="2026-02-25T23:56:34+07:00" level=debug msg="completed challenge" Feb 25 23:56:34 volumio go-librespot[32436]: time="2026-02-25T23:56: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 25 23:56:34 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 25 23:56:34 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 25 23:56:34 volumio volumio[32061]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Feb 25 23:56:34 volumio volumio[32061]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 25 23:56:34 volumio volumio[32061]: Error: socket hang up Feb 25 23:56:34 volumio volumio[32061]: at connResetException (node:internal/errors:720:14) Feb 25 23:56:34 volumio volumio[32061]: at Socket.socketOnEnd (node:_http_client:519:23) Feb 25 23:56:34 volumio volumio[32061]: at Socket.emit (node:events:526:35) Feb 25 23:56:34 volumio volumio[32061]: at endReadableNT (node:internal/streams/readable:1376:12) Feb 25 23:56:34 volumio volumio[32061]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Feb 25 23:56:34 volumio volumio[32061]: code: 'ECONNRESET', Feb 25 23:56:34 volumio volumio[32061]: response: undefined Feb 25 23:56:34 volumio volumio[32061]: } Feb 25 23:56:34 volumio volumio[32061]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 25 23:56:36 volumio sudo[32462]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-25 23:55' Feb 25 23:56:36 volumio sudo[32462]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="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"