Feb 11 09:11:01 volumio sudo[4897]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-11 09:10'
Feb 11 09:11:01 volumio sudo[4897]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 11 09:11:01 volumio sudo[4897]: pam_unix(sudo:session): session closed for user root
Feb 11 09:11:02 volumio volumio-remote-updater[643]: [2026-02-11 09:11:02] [error] handle_read_frame error: asio.system:104 (Connection reset by peer)
Feb 11 09:11:02 volumio volumio-remote-updater[643]: [2026-02-11 09:11:02] [disconnect] Disconnect close local:[1006,Connection reset by peer] remote:[1006]
Feb 11 09:11:02 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE
Feb 11 09:11:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15.
Feb 11 09:11:02 volumio systemd[1]: volumio.service: Failed with result 'exit-code'.
Feb 11 09:11:02 volumio systemd[1]: volumio.service: Consumed 55.584s CPU time.
Feb 11 09:11:02 volumio systemd[1]: Started dynamicswap.service - dynamicswap service.
Feb 11 09:11:02 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 11 09:11:02 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 11 09:11:02 volumio go-librespot[4911]: go-librespot daemon starting...
Feb 11 09:11:02 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 11533.
Feb 11 09:11:02 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module.
Feb 11 09:11:02 volumio systemd[1]: volumio.service: Consumed 55.584s CPU time.
Feb 11 09:11:02 volumio systemd[1]: Started volumio.service - Volumio Backend Module.
Feb 11 09:11:02 volumio systemd[1]: dynamicswap.service: Deactivated successfully.
Feb 11 09:11:02 volumio go-librespot[4915]: time="2026-02-11T09:11:02+07:00" level=info msg="running go-librespot 0.4.0"
Feb 11 09:11:02 volumio go-librespot[4915]: time="2026-02-11T09:11:02+07:00" level=debug msg="app state loaded"
Feb 11 09:11:02 volumio go-librespot[4915]: time="2026-02-11T09:11:02+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 11 09:11:03 volumio go-librespot[4915]: time="2026-02-11T09:11:03+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 11 09:11:03 volumio go-librespot[4915]: time="2026-02-11T09:11:03+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Feb 11 09:11:03 volumio go-librespot[4915]: time="2026-02-11T09:11:03+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Feb 11 09:11:03 volumio go-librespot[4915]: time="2026-02-11T09:11:03+07:00" level=info msg="zeroconf server listening on port 33443"
Feb 11 09:11:03 volumio go-librespot[4915]: time="2026-02-11T09:11:03+07:00" level=debug msg="obtained new client token: AAD7K3/Os2M28OJ+HKMyBFCN/qtfFHkWhMI+IcFFwp/4w/HzP9ncByQIbRiTL4+gbepuONalj/JYakROTllVl9opXk2I0mtSPpHaHPYQrDblx+CVSrIvg+M1ruMBo/ymOKlXZoLuyuI+BXtkHM0QMuHbfHwHSRpQTo/iJvaHzxFh4NtnmUB6/01JIg2rhx4iFGF8Hg/wSe7FM8JiXpNt0WMUpPfO0lhFRExV48EiU/09gLjMbE+6Wbv6yw=="
Feb 11 09:11:03 volumio go-librespot[4915]: time="2026-02-11T09:11:03+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 11 09:11:03 volumio go-librespot[4915]: time="2026-02-11T09:11:03+07:00" level=debug msg="completed keyexchange"
Feb 11 09:11:03 volumio go-librespot[4915]: time="2026-02-11T09:11:03+07:00" level=debug msg="completed challenge"
Feb 11 09:11:03 volumio go-librespot[4915]: time="2026-02-11T09:11:03+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 11 09:11:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 11 09:11:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 11 09:11:06 volumio volumio[4920]: info: -------------------------------------------
Feb 11 09:11:06 volumio volumio[4920]: info: -----            Volumio3              ----
Feb 11 09:11:06 volumio volumio[4920]: info: -------------------------------------------
Feb 11 09:11:06 volumio volumio[4920]: info: -----          System startup          ----
Feb 11 09:11:06 volumio volumio[4920]: info: -------------------------------------------
Feb 11 09:11:07 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16.
Feb 11 09:11:07 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 11 09:11:07 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 11 09:11:07 volumio go-librespot[4942]: go-librespot daemon starting...
Feb 11 09:11:07 volumio go-librespot[4943]: time="2026-02-11T09:11:07+07:00" level=info msg="running go-librespot 0.4.0"
Feb 11 09:11:07 volumio go-librespot[4943]: time="2026-02-11T09:11:07+07:00" level=debug msg="app state loaded"
Feb 11 09:11:07 volumio go-librespot[4943]: time="2026-02-11T09:11:07+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 11 09:11:07 volumio volumio-remote-updater[643]: [2026-02-11 09:11:07] [connect] Successful connection
Feb 11 09:11:07 volumio go-librespot[4943]: time="2026-02-11T09:11:07+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 11 09:11:07 volumio go-librespot[4943]: time="2026-02-11T09:11:07+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 11 09:11:07 volumio go-librespot[4943]: time="2026-02-11T09:11:07+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 11 09:11:07 volumio go-librespot[4943]: time="2026-02-11T09:11:07+07:00" level=info msg="zeroconf server listening on port 33043"
Feb 11 09:11:07 volumio volumio[4920]: info: MYVOLUMIO Environment detected
Feb 11 09:11:07 volumio volumio[4920]: info: Plugin folders cleanup
Feb 11 09:11:07 volumio volumio[4920]: info: Scanning into folder /volumio/app/plugins/
Feb 11 09:11:07 volumio volumio[4920]: info: Scanning category audio_interface
Feb 11 09:11:07 volumio volumio[4920]: info: Scanning category miscellanea
Feb 11 09:11:07 volumio volumio[4920]: info: Scanning category music_service
Feb 11 09:11:07 volumio volumio[4920]: info: Scanning category plugins.json
Feb 11 09:11:07 volumio volumio[4920]: info: Scanning category system_controller
Feb 11 09:11:07 volumio volumio[4920]: info: Scanning category user_interface
Feb 11 09:11:07 volumio volumio[4920]: info: Scanning into folder /data/plugins/
Feb 11 09:11:07 volumio volumio[4920]: info: Scanning category music_service
Feb 11 09:11:07 volumio volumio[4920]: info: Plugin folders cleanup completed
Feb 11 09:11:08 volumio volumio[4920]: info: -------------------------------------------
Feb 11 09:11:08 volumio volumio[4920]: info: -----      Core plugins startup        ----
Feb 11 09:11:08 volumio volumio[4920]: info: -------------------------------------------
Feb 11 09:11:08 volumio volumio[4920]: info: Loading plugins from folder /volumio/app/plugins/
Feb 11 09:11:08 volumio volumio[4920]: info: Adding plugin upnp to MyMusic Plugins
Feb 11 09:11:08 volumio volumio[4920]: info: Adding plugin airplay_emulation to MyMusic Plugins
Feb 11 09:11:08 volumio volumio[4920]: info: Adding plugin upnp_browser to MyMusic Plugins
Feb 11 09:11:08 volumio go-librespot[4943]: time="2026-02-11T09:11:08+07:00" level=debug msg="obtained new client token: AACEPvt316fBqi5HHrp3Gou/+CsB1I+eYS2q2jYY8rxdGSFe4lbwlLd2KjunjjQz9jxx3xPPAj7upf3T3BD6m4or28Ovb6L8giwFeAnAvmCChIRFgKY5kYXdt3lh5fqDZ5uXhNe/xa56qcC+dBrmWtDnm7AITE1UMpkV9bV8wPgfTJcMnODGVoFVWxuimqE57tuM2rhYuqdGweXF8ZSV3+nPq9DR2qVRDh4GnCp/WQGERplapRHU8A/9eg=="
Feb 11 09:11:08 volumio volumio[4920]: info: Loading plugins from folder /data/plugins/
Feb 11 09:11:08 volumio volumio[4920]: info: Loading plugin "system"...
Feb 11 09:11:08 volumio volumio[4920]: info: Loading plugin "appearance"...
Feb 11 09:11:08 volumio go-librespot[4943]: time="2026-02-11T09:11:08+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 11 09:11:08 volumio go-librespot[4943]: time="2026-02-11T09:11:08+07:00" level=debug msg="completed keyexchange"
Feb 11 09:11:08 volumio go-librespot[4943]: time="2026-02-11T09:11:08+07:00" level=debug msg="completed challenge"
Feb 11 09:11:08 volumio go-librespot[4943]: time="2026-02-11T09:11:08+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Feb 11 09:11:08 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 11 09:11:08 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 11 09:11:09 volumio volumio[4920]: info: Loading plugin "network"...
Feb 11 09:11:10 volumio volumio[4920]: info: Refreshing Cached IP Addresses
Feb 11 09:11:10 volumio sudo[4957]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Feb 11 09:11:10 volumio sudo[4957]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 11 09:11:10 volumio sudo[4959]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Feb 11 09:11:10 volumio sudo[4959]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 11 09:11:10 volumio sudo[4959]: pam_unix(sudo:session): session closed for user root
Feb 11 09:11:10 volumio sudo[4957]: pam_unix(sudo:session): session closed for user root
Feb 11 09:11:10 volumio volumio[4920]: info: Loading plugin "services"...
Feb 11 09:11:10 volumio volumio[4920]: info: Loading plugin "alsa_controller"...
Feb 11 09:11:10 volumio sudo[4967]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan
Feb 11 09:11:10 volumio sudo[4967]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 11 09:11:10 volumio volumio[4920]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Feb 11 09:11:10 volumio volumio[4920]: info: Loading plugin "wizard"...
Feb 11 09:11:10 volumio volumio[4920]: info: Loading plugin "networkfs"...
Feb 11 09:11:10 volumio volumio[4920]: info: Starting Udev Watcher for removable devices
Feb 11 09:11:10 volumio volumio[4920]: info: Ignoring mount for partition: boot
Feb 11 09:11:10 volumio volumio[4920]: info: Ignoring mount for partition: volumio
Feb 11 09:11:10 volumio volumio[4920]: info: Ignoring mount for partition: volumio_data
Feb 11 09:11:10 volumio volumio[4920]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Feb 11 09:11:10 volumio volumio[4920]: info: Loading plugin "volumio_command_line_client"...
Feb 11 09:11:10 volumio volumio[4920]: info: Loading plugin "upnp"...
Feb 11 09:11:10 volumio volumio[4920]: info: [1770775870400] Starting Upmpd Daemon
Feb 11 09:11:10 volumio volumio[4920]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Feb 11 09:11:10 volumio volumio[4920]: info: Loading plugin "my_music"...
Feb 11 09:11:10 volumio volumio[4920]: info: Loading plugin "mpd"...
Feb 11 09:11:11 volumio volumio[4920]: info: Loading plugin "upnp_browser"...
Feb 11 09:11:11 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17.
Feb 11 09:11:11 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 11 09:11:11 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 11 09:11:11 volumio go-librespot[4990]: go-librespot daemon starting...
Feb 11 09:11:11 volumio go-librespot[4991]: time="2026-02-11T09:11:11+07:00" level=info msg="running go-librespot 0.4.0"
Feb 11 09:11:11 volumio go-librespot[4991]: time="2026-02-11T09:11:11+07:00" level=debug msg="app state loaded"
Feb 11 09:11:11 volumio go-librespot[4991]: time="2026-02-11T09:11:11+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 11 09:11:12 volumio go-librespot[4991]: time="2026-02-11T09:11: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 11 09:11:12 volumio go-librespot[4991]: time="2026-02-11T09:11:12+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 11 09:11:12 volumio go-librespot[4991]: time="2026-02-11T09:11:12+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 11 09:11:12 volumio go-librespot[4991]: time="2026-02-11T09:11:12+07:00" level=info msg="zeroconf server listening on port 46599"
Feb 11 09:11:12 volumio go-librespot[4991]: time="2026-02-11T09:11:12+07:00" level=debug msg="obtained new client token: AAAD85EL/d9sqstXsS4Hxyv3u2bA9n+J2TuUYwAcxOwyCioGsAh5geY3UEi0cJdg3Q7Xi/5H9DcdUkNF+3+xk7PCaZZ9J5cOGYBhISmXxxgANF73fD+tBFC6wv9LsVtxvb/qSZOt9bKo9xpIB0D2EforO1oDZrU2r8hqMt18FBwYPk/kqZMXhtvbz4E+EOD200L9MWXi8wjNpUXPXAyWcLG84RJOxoy++a40B96F9DUgwsV/7s6BEKsemg=="
Feb 11 09:11:12 volumio go-librespot[4991]: time="2026-02-11T09:11:12+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 11 09:11:12 volumio go-librespot[4991]: time="2026-02-11T09:11:12+07:00" level=debug msg="completed keyexchange"
Feb 11 09:11:12 volumio go-librespot[4991]: time="2026-02-11T09:11:12+07:00" level=debug msg="completed challenge"
Feb 11 09:11:12 volumio go-librespot[4991]: time="2026-02-11T09:11:12+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 11 09:11:12 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 11 09:11:12 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 11 09:11:12 volumio sudo[4967]: pam_unix(sudo:session): session closed for user root
Feb 11 09:11:14 volumio volumio[4920]: info: Starting UPNP Browser
Feb 11 09:11:14 volumio volumio[4920]: info: Loading plugin "alarm-clock"...
Feb 11 09:11:14 volumio volumio[4920]: info: Loading plugin "airplay_emulation"...
Feb 11 09:11:14 volumio volumio[4920]: info: Starting Shairport Sync
Feb 11 09:11:14 volumio volumio[4920]: info: Loading plugin "last_100"...
Feb 11 09:11:14 volumio volumio[4920]: info: Loading plugin "webradio"...
Feb 11 09:11:14 volumio volumio[4920]: info: Loading plugin "i2s_dacs"...
Feb 11 09:11:14 volumio volumio[4920]: info: Loading plugin "volumiodiscovery"...
Feb 11 09:11:14 volumio volumio[4920]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Feb 11 09:11:14 volumio volumio[4920]: *** WARNING *** Please fix your application to use the native API of Avahi!
Feb 11 09:11:14 volumio node[4920]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Feb 11 09:11:14 volumio volumio[4920]: *** WARNING *** For more information see 
Feb 11 09:11:14 volumio volumio[4920]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Feb 11 09:11:14 volumio volumio[4920]: *** WARNING *** Please fix your application to use the native API of Avahi!
Feb 11 09:11:14 volumio volumio[4920]: *** WARNING *** For more information see 
Feb 11 09:11:14 volumio node[4920]: *** WARNING *** Please fix your application to use the native API of Avahi!
Feb 11 09:11:14 volumio node[4920]: *** WARNING *** For more information see 
Feb 11 09:11:14 volumio node[4920]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Feb 11 09:11:14 volumio node[4920]: *** WARNING *** Please fix your application to use the native API of Avahi!
Feb 11 09:11:14 volumio node[4920]: *** WARNING *** For more information see 
Feb 11 09:11:14 volumio volumio[4920]: info: Applying required configuration parameters for plugin volumiodiscovery
Feb 11 09:11:14 volumio volumio[4920]: info: Discovery: Started advertising with name: Volumio
Feb 11 09:11:14 volumio volumio[4920]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Feb 11 09:11:14 volumio volumio[4920]: info: Loading plugin "spop"...
Feb 11 09:11:15 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18.
Feb 11 09:11:15 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 11 09:11:15 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 11 09:11:15 volumio go-librespot[5002]: go-librespot daemon starting...
Feb 11 09:11:15 volumio go-librespot[5003]: time="2026-02-11T09:11:15+07:00" level=info msg="running go-librespot 0.4.0"
Feb 11 09:11:15 volumio go-librespot[5003]: time="2026-02-11T09:11:15+07:00" level=debug msg="app state loaded"
Feb 11 09:11:15 volumio go-librespot[5003]: time="2026-02-11T09:11:15+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 11 09:11:16 volumio go-librespot[5003]: time="2026-02-11T09:11: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 11 09:11:16 volumio go-librespot[5003]: time="2026-02-11T09:11:16+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 11 09:11:16 volumio go-librespot[5003]: time="2026-02-11T09:11:16+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 11 09:11:16 volumio go-librespot[5003]: time="2026-02-11T09:11:16+07:00" level=info msg="zeroconf server listening on port 40011"
Feb 11 09:11:16 volumio volumio[4920]: info: Loading plugin "ytcr"...
Feb 11 09:11:16 volumio go-librespot[5003]: time="2026-02-11T09:11:16+07:00" level=debug msg="obtained new client token: AABqHPUH/iSCZQXQtu8DRveJu1lPKbYOO7lRK/39TcccR/8AKFxm2lMkc5eDwMEBMm8CnDX7VNm/p+qciScH4NJJ7S0cha63GRpgrdrGsqKw5ZCmFeBGgOb6T7BuGmcqYOXawOqJY5cbD4RrGze1uS31rVrE5AxtL5tlYKdLxIZR9ZolzCNqMJ/SXyza1OqxAF0bjUQD1kBVG1vlyOfaztR4stN9Xh0Xc1TdgT2o8PQlmsOaukxcIkUNCQ=="
Feb 11 09:11:16 volumio go-librespot[5003]: time="2026-02-11T09:11:16+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 11 09:11:16 volumio go-librespot[5003]: time="2026-02-11T09:11:16+07:00" level=debug msg="completed keyexchange"
Feb 11 09:11:16 volumio go-librespot[5003]: time="2026-02-11T09:11:16+07:00" level=debug msg="completed challenge"
Feb 11 09:11:17 volumio go-librespot[5003]: time="2026-02-11T09:11: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 11 09:11:17 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 11 09:11:17 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 11 09:11:19 volumio volumio[4920]: info: Loading plugin "ytmusic"...
Feb 11 09:11:20 volumio volumio-remote-updater[643]: [2026-02-11 09:11:20] [connect] Successful connection
Feb 11 09:11:20 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 19.
Feb 11 09:11:20 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 11 09:11:20 volumio volumio[4920]: info: Loading plugin "outputs"...
Feb 11 09:11:20 volumio volumio[4920]: info: Loading plugin "albumart"...
Feb 11 09:11:20 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 11 09:11:20 volumio volumio[4920]: info: Plugin example_plugin is not enabled
Feb 11 09:11:20 volumio volumio[4920]: info: Loading plugin "inputs"...
Feb 11 09:11:20 volumio go-librespot[5024]: go-librespot daemon starting...
Feb 11 09:11:20 volumio volumio[4920]: info: Loading plugin "updater_comm"...
Feb 11 09:11:20 volumio go-librespot[5026]: time="2026-02-11T09:11:20+07:00" level=info msg="running go-librespot 0.4.0"
Feb 11 09:11:20 volumio go-librespot[5026]: time="2026-02-11T09:11:20+07:00" level=debug msg="app state loaded"
Feb 11 09:11:20 volumio go-librespot[5026]: time="2026-02-11T09:11:20+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 11 09:11:20 volumio volumio[4920]: info: Plugin mpdemulation is not enabled
Feb 11 09:11:20 volumio volumio[4920]: info: Loading plugin "rest_api"...
Feb 11 09:11:20 volumio volumio[4920]: info: Loading plugin "websocket"...
Feb 11 09:11:20 volumio volumio[4920]: info: Starting Socket.io Server version 1.7.4
Feb 11 09:11:20 volumio volumio[4920]: info: Loading plugin "RoonBridge"...
Feb 11 09:11:21 volumio go-librespot[5026]: time="2026-02-11T09:11: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 11 09:11:21 volumio go-librespot[5026]: time="2026-02-11T09:11:21+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 11 09:11:21 volumio go-librespot[5026]: time="2026-02-11T09:11:21+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 11 09:11:21 volumio go-librespot[5026]: time="2026-02-11T09:11:21+07:00" level=info msg="zeroconf server listening on port 40671"
Feb 11 09:11:21 volumio volumio[4920]: info: Applying required configuration parameters for plugin RoonBridge
Feb 11 09:11:21 volumio go-librespot[5026]: time="2026-02-11T09:11:21+07:00" level=debug msg="obtained new client token: AAC2v8t8mBosjawrkmmHdwIUG0C6LUchM5qqFFxFtfy/GI1MDgsHKrII9NQ4EJpATVLirrsJ8TfOOOglOIKez2yXoqTaJu+waBSBBj5gGBXMYLFUiPTpkH+zRUfZoRakdTZBpp0hXF5ySae5KMSrm3u5yA0rYaxmMemZhA82cW69+NZ3JJb0rVl7YtH4PeGA3eOkOsWrgwtcz5TgjuhI/Oox55lmTCNfdLQr0mwmKVEzEhllLhbdQUcnTw=="
Feb 11 09:11:21 volumio volumio[4920]: info: Loading i18n strings for locale en
Feb 11 09:11:21 volumio volumio[4920]: Updating browse sources language
Feb 11 09:11:21 volumio volumio[4920]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 11 09:11:21 volumio go-librespot[5026]: time="2026-02-11T09:11:21+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 11 09:11:21 volumio go-librespot[5026]: time="2026-02-11T09:11:21+07:00" level=debug msg="completed keyexchange"
Feb 11 09:11:21 volumio go-librespot[5026]: time="2026-02-11T09:11:21+07:00" level=debug msg="completed challenge"
Feb 11 09:11:21 volumio volumio[5025]: Forking 3 albumart workers
Feb 11 09:11:21 volumio go-librespot[5026]: time="2026-02-11T09:11: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 11 09:11:21 volumio volumio[4920]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Feb 11 09:11:21 volumio volumio[4920]: info: CoreCommandRouter::initPlayerControls
Feb 11 09:11:21 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 11 09:11:21 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 11 09:11:21 volumio volumio[4920]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 09:11:21 volumio volumio[4920]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 09:11:21 volumio volumio[4920]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 09:11:21 volumio volumio[4920]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 09:11:21 volumio volumio[4920]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 09:11:21 volumio volumio[4920]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 09:11:21 volumio volumio[4920]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 09:11:21 volumio volumio[4920]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 09:11:21 volumio volumio[4920]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Feb 11 09:11:21 volumio volumio[4920]: Express server listening on port 3000
Feb 11 09:11:21 volumio volumio[4920]:  [Metrics]  WebUI:  16s 211.42ms 
Feb 11 09:11:21 volumio volumio[4920]: info: CoreStateMachine::resetVolumioState
Feb 11 09:11:21 volumio volumio[4920]: info: CoreStateMachine::getcurrentVolume
Feb 11 09:11:21 volumio volumio[4920]: info: CoreCommandRouter::volumioRetrievevolume
Feb 11 09:11:21 volumio sudo[5075]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Feb 11 09:11:21 volumio sudo[5075]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 11 09:11:21 volumio sudo[5077]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Feb 11 09:11:21 volumio sudo[5077]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 11 09:11:21 volumio sudo[5075]: pam_unix(sudo:session): session closed for user root
Feb 11 09:11:21 volumio sudo[5077]: pam_unix(sudo:session): session closed for user root
Feb 11 09:11:22 volumio volumio[4920]: info: Volumio Network Manager: Network status updated: 1
Feb 11 09:11:22 volumio volumio[4920]: info: VolumeController:: Volume=100 Mute =false
Feb 11 09:11:22 volumio volumio[4920]: info: CoreStateMachine::pushState
Feb 11 09:11:22 volumio volumio[4920]: info: CorePlayQueue::getTrack 0
Feb 11 09:11:22 volumio volumio[4920]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Feb 11 09:11:22 volumio volumio[4920]: info: CoreCommandRouter::volumioPushState
Feb 11 09:11:22 volumio volumio[4920]: info: CoreStateMachine::updateTrackBlock
Feb 11 09:11:22 volumio volumio[4920]: info: CorePlayQueue::getTrackBlock
Feb 11 09:11:22 volumio volumio[4920]: info: CoreCommandRouter::volumioRetrievevolume
Feb 11 09:11:22 volumio volumio-remote-updater[643]: [2026-02-11 09:11:22] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770775880 101
Feb 11 09:11:22 volumio volumio[4920]: 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 11 09:11:22 volumio volumio[4920]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 11 09:11:22 volumio volumio[4920]: info: Reloading queue from file
Feb 11 09:11:22 volumio volumio[4920]: info: CoreStateMachine::setRepeat null single undefined
Feb 11 09:11:22 volumio volumio[4920]: info: CoreStateMachine::pushState
Feb 11 09:11:22 volumio volumio[4920]: info: CorePlayQueue::getTrack 0
Feb 11 09:11:22 volumio volumio[4920]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Feb 11 09:11:22 volumio volumio[4920]: info: CoreCommandRouter::volumioPushState
Feb 11 09:11:22 volumio volumio[4920]: info: CoreStateMachine::setRandom null
Feb 11 09:11:22 volumio volumio[4920]: info: CoreStateMachine::pushState
Feb 11 09:11:22 volumio volumio[4920]: info: CorePlayQueue::getTrack 0
Feb 11 09:11:22 volumio volumio[4920]: info: CoreCommandRouter::volumioPushState
Feb 11 09:11:22 volumio volumio[4920]: info: Setting Device type: Raspberry PI
Feb 11 09:11:22 volumio volumio[4920]: info: Completed loading Core Plugins
Feb 11 09:11:22 volumio volumio[4920]: info: Preparing to generate the ALSA configuration file
Feb 11 09:11:22 volumio volumio[4920]: info: VolumeController:: Volume=100 Mute =false
Feb 11 09:11:22 volumio volumio[4920]: info: CoreStateMachine::pushState
Feb 11 09:11:22 volumio volumio[4920]: info: CorePlayQueue::getTrack 0
Feb 11 09:11:22 volumio volumio[4920]: info: CoreCommandRouter::volumioPushState
Feb 11 09:11:22 volumio volumio[4920]: info: Asound.conf file unchanged, so no further update is needed
Feb 11 09:11:22 volumio volumio[4920]: info: Output device has changed, restarting MPD
Feb 11 09:11:22 volumio volumio[4920]: info: Output device has changed, restarting Shairport Sync
Feb 11 09:11:22 volumio volumio[4920]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 09:11:22 volumio volumio[4920]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 11 09:11:22 volumio sudo[5094]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service
Feb 11 09:11:22 volumio sudo[5094]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 11 09:11:22 volumio sudo[5096]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Feb 11 09:11:22 volumio sudo[5096]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 11 09:11:22 volumio volumio[4920]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Feb 11 09:11:22 volumio sudo[5096]: pam_unix(sudo:session): session closed for user root
Feb 11 09:11:22 volumio sudo[5098]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Feb 11 09:11:22 volumio volumio[4920]: info: ___________ START PLUGINS ___________
Feb 11 09:11:22 volumio sudo[5098]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 11 09:11:22 volumio volumio[4920]: info: ControllerMpd::onStart: Initializing MPD
Feb 11 09:11:22 volumio volumio[4920]: info: Creating MPD Configuration file
Feb 11 09:11:23 volumio sudo[5107]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Feb 11 09:11:23 volumio sudo[5107]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 11 09:11:23 volumio systemd[1]: Stopping mpd.service - Music Player Daemon...
Feb 11 09:11:23 volumio volumio[4920]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Feb 11 09:11:23 volumio volumio[4920]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 11 09:11:23 volumio sudo[5094]: pam_unix(sudo:session): session closed for user root
Feb 11 09:11:23 volumio sudo[5107]: pam_unix(sudo:session): session closed for user root
Feb 11 09:11:23 volumio volumio[4920]: info: [1770775883046] CoreMusicLibrary::Adding element Media Servers
Feb 11 09:11:23 volumio volumio[4920]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 11 09:11:23 volumio volumio[4920]: info: UPNP Browser: Client initialized successfully
Feb 11 09:11:23 volumio sudo[5109]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Feb 11 09:11:23 volumio sudo[5109]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 11 09:11:23 volumio systemd[1]: mpd.service: Deactivated successfully.
Feb 11 09:11:23 volumio systemd[1]: Stopped mpd.service - Music Player Daemon.
Feb 11 09:11:23 volumio systemd[1]: mpd.service: Consumed 7.229s CPU time.
Feb 11 09:11:23 volumio systemd[1]: mpd.socket: Deactivated successfully.
Feb 11 09:11:23 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket.
Feb 11 09:11:23 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket...
Feb 11 09:11:23 volumio volumio[4920]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 09:11:23 volumio volumio[4920]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 11 09:11:23 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket.
Feb 11 09:11:23 volumio volumio[4920]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Feb 11 09:11:23 volumio volumio[4920]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 09:11:23 volumio volumio[4920]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 11 09:11:23 volumio systemd[1]: Starting mpd.service - Music Player Daemon...
Feb 11 09:11:23 volumio volumio[4920]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Feb 11 09:11:23 volumio volumio[4920]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 11 09:11:23 volumio volumio[4920]: info: [1770775883418] CoreMusicLibrary::Adding element Last_100
Feb 11 09:11:23 volumio volumio[4920]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 11 09:11:23 volumio volumio[4920]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 11 09:11:23 volumio volumio[4920]: info: [1770775883434] CoreMusicLibrary::Adding element Webradio
Feb 11 09:11:23 volumio systemd[1]: mpd.service: Deactivated successfully.
Feb 11 09:11:23 volumio systemd[1]: Stopped mpd.service - Music Player Daemon.
Feb 11 09:11:23 volumio systemd[1]: mpd.socket: Deactivated successfully.
Feb 11 09:11:23 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket.
Feb 11 09:11:23 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket...
Feb 11 09:11:23 volumio volumio[4920]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 11 09:11:23 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket.
Feb 11 09:11:23 volumio systemd[1]: Starting mpd.service - Music Player Daemon...
Feb 11 09:11:23 volumio volumio[4920]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Feb 11 09:11:23 volumio volumio[4920]: info: Initializing BBC Radios
Feb 11 09:11:23 volumio volumio[4920]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Feb 11 09:11:23 volumio volumio[4920]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 11 09:11:23 volumio volumio[4920]: info: Creating Spotify config file
Feb 11 09:11:23 volumio volumio[4920]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 09:11:23 volumio sudo[5123]:     root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log
Feb 11 09:11:23 volumio sudo[5123]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
Feb 11 09:11:23 volumio sudo[5123]: pam_unix(sudo:session): session closed for user root
Feb 11 09:11:24 volumio volumio[5043]: Starting albumart workers
Feb 11 09:11:24 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 20.
Feb 11 09:11:24 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 11 09:11:24 volumio volumio[5044]: Starting albumart workers
Feb 11 09:11:24 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 11 09:11:24 volumio go-librespot[5139]: go-librespot daemon starting...
Feb 11 09:11:24 volumio volumio[4920]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 11 09:11:24 volumio volumio[4920]: info: [1770775884984] CoreMusicLibrary::Adding element YouTube Music
Feb 11 09:11:24 volumio volumio[4920]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 11 09:11:24 volumio volumio[4920]: Cannot find translation for source YouTube Music
Feb 11 09:11:25 volumio volumio[4920]: info: Volumio Calling Home
Feb 11 09:11:25 volumio go-librespot[5140]: time="2026-02-11T09:11:25+07:00" level=info msg="running go-librespot 0.4.0"
Feb 11 09:11:25 volumio volumio[5045]: Starting albumart workers
Feb 11 09:11:25 volumio sudo[5147]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service
Feb 11 09:11:25 volumio sudo[5147]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 11 09:11:25 volumio sudo[5147]: pam_unix(sudo:session): session closed for user root
Feb 11 09:11:25 volumio go-librespot[5140]: time="2026-02-11T09:11:25+07:00" level=info msg="zeroconf server listening on port 41695"
Feb 11 09:11:25 volumio volumio[4920]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7
Feb 11 09:11:25 volumio volumio[4920]: info: Discovery: Found device Volumio
Feb 11 09:11:25 volumio volumio[4920]: info: CoreCommandRouter::volumioGetState
Feb 11 09:11:25 volumio volumio[4920]: info: CorePlayQueue::getTrack 0
Feb 11 09:11:25 volumio volumio[4920]: info: Discovery: this is already registered,  921648ed-0557-4d70-9927-1420682efcc7
Feb 11 09:11:25 volumio volumio[4920]: info: Discovery: Found device Volumio
Feb 11 09:11:25 volumio volumio[4920]: info: CoreCommandRouter::volumioGetState
Feb 11 09:11:25 volumio volumio[4920]: info: CorePlayQueue::getTrack 0
Feb 11 09:11:26 volumio volumio[4920]: info: MPD Permissions set
Feb 11 09:11:26 volumio volumio[4920]: info: MPD Permissions set
Feb 11 09:11:26 volumio volumio[4920]: info: Upmpdcli Daemon Started
Feb 11 09:11:26 volumio volumio[4920]: info: Volumio called home
Feb 11 09:11:26 volumio volumio[4920]: info: Spotify config file written
Feb 11 09:11:26 volumio sudo[5154]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service
Feb 11 09:11:26 volumio sudo[5154]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 11 09:11:26 volumio volumio[4920]: 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 11 09:11:26 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon...
Feb 11 09:11:26 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully.
Feb 11 09:11:26 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 11 09:11:26 volumio volumio[4920]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 09:11:26 volumio volumio[4920]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 09:11:26 volumio volumio[4920]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 09:11:26 volumio volumio[4920]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 09:11:26 volumio volumio[4920]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 09:11:26 volumio volumio[4920]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 09:11:26 volumio volumio[4920]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 09:11:26 volumio volumio[4920]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 09:11:26 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 11 09:11:26 volumio go-librespot[5156]: go-librespot daemon starting...
Feb 11 09:11:26 volumio sudo[5154]: pam_unix(sudo:session): session closed for user root
Feb 11 09:11:26 volumio go-librespot[5159]: time="2026-02-11T09:11:26+07:00" level=info msg="running go-librespot 0.4.0"
Feb 11 09:11:26 volumio go-librespot[5159]: time="2026-02-11T09:11:26+07:00" level=debug msg="app state loaded"
Feb 11 09:11:26 volumio go-librespot[5159]: time="2026-02-11T09:11:26+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 11 09:11:26 volumio volumio[4920]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 11 09:11:26 volumio volumio[4920]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 09:11:26 volumio volumio[4920]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 09:11:26 volumio volumio[4920]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 09:11:26 volumio volumio[4920]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 09:11:26 volumio volumio[4920]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 09:11:26 volumio volumio[4920]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 09:11:26 volumio volumio[4920]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 09:11:26 volumio volumio[4920]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 09:11:26 volumio volumio[4920]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 09:11:26 volumio volumio[4920]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 11 09:11:26 volumio volumio[4920]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 09:11:26 volumio volumio[4920]: info: No need to fix Spotify hosts
Feb 11 09:11:27 volumio go-librespot[5159]: time="2026-02-11T09:11: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-gew1.spotify.com:80]"
Feb 11 09:11:27 volumio go-librespot[5159]: time="2026-02-11T09:11:27+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 11 09:11:27 volumio go-librespot[5159]: time="2026-02-11T09:11:27+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 11 09:11:27 volumio go-librespot[5159]: time="2026-02-11T09:11:27+07:00" level=info msg="zeroconf server listening on port 46473"
Feb 11 09:11:27 volumio go-librespot[5159]: time="2026-02-11T09:11:27+07:00" level=debug msg="obtained new client token: AAABfZvynaMcL7gDhQRMS2/fy7dl3+TC2LKp1a2KUdPPUlQrDyyGTi/wLLnY+cRlORFZBioz4DD+uLtiVrQVKRZ8cCdwDXd0Mnf8qhOEJQ5HSytP9ZFXoidM81UWyQZLwA5ulWxXrfOnPrs8vxtjC1zzAbCWtQbVKZmz2js9Bi67XcUgJO8j3Wxb1XPImXwduFDjdnrGZ88R53hxUxpACZ87zMRMoLfP6EZnpZ1zqrjdpDKsJWDOIpUExw=="
Feb 11 09:11:27 volumio go-librespot[5159]: time="2026-02-11T09:11:27+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 11 09:11:27 volumio go-librespot[5159]: time="2026-02-11T09:11:27+07:00" level=debug msg="completed keyexchange"
Feb 11 09:11:27 volumio go-librespot[5159]: time="2026-02-11T09:11:27+07:00" level=debug msg="completed challenge"
Feb 11 09:11:27 volumio go-librespot[5159]: time="2026-02-11T09:11: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 11 09:11:27 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 11 09:11:27 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 11 09:11:27 volumio volumio[4920]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------
Feb 11 09:11:27 volumio volumio[4920]: SPOTIFY: BQD10xc98mH90k_QQehJ0PArt3hTT6HmaPf3pAqTFPpvO0A2YKBYH-db5q85ql3GM2HhJdMwedEFDsWh-Q88cgRjHjhjfexQN3wdB2TVB6kBIDzwUDt2WJPytaytil73nNyhVIxYukLTQkjY4aXIfLSq3pTqYtbEOFKHYF6IiuefdsnORGUGPeMevWg-e7PIChUt6ix7cB21ys_OJIsG7VjmcDGTuS7svkRLcDAjTBXdiIwIvMYdvrV_syoEeFaJtyrL6sLf6zvnps5OZ2XaLtlnMEj_m1feLOBtvwcEZYu03MN8iax8dRNH
Feb 11 09:11:27 volumio volumio[4920]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------
Feb 11 09:11:27 volumio volumio[4920]: info: New Spotify access token = BQD10xc98mH90k_QQehJ0PArt3hTT6HmaPf3pAqTFPpvO0A2YKBYH-db5q85ql3GM2HhJdMwedEFDsWh-Q88cgRjHjhjfexQN3wdB2TVB6kBIDzwUDt2WJPytaytil73nNyhVIxYukLTQkjY4aXIfLSq3pTqYtbEOFKHYF6IiuefdsnORGUGPeMevWg-e7PIChUt6ix7cB21ys_OJIsG7VjmcDGTuS7svkRLcDAjTBXdiIwIvMYdvrV_syoEeFaJtyrL6sLf6zvnps5OZ2XaLtlnMEj_m1feLOBtvwcEZYu03MN8iax8dRNH
Feb 11 09:11:27 volumio volumio[4920]: info: Spotify credentials grant success - running version from March 24, 2019
Feb 11 09:11:28 volumio volumio[4920]: info: Starting Shairport Sync
Feb 11 09:11:28 volumio volumio[4920]: info: Starting Shairport Sync
Feb 11 09:11:28 volumio volumio[4920]: info: Starting Shairport Sync
Feb 11 09:11:28 volumio sudo[5194]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Feb 11 09:11:28 volumio sudo[5194]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 11 09:11:28 volumio sudo[5198]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Feb 11 09:11:28 volumio sudo[5198]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 11 09:11:28 volumio sudo[5196]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Feb 11 09:11:28 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver...
Feb 11 09:11:28 volumio sudo[5196]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 11 09:11:28 volumio systemd[1]: shairport-sync.service: Deactivated successfully.
Feb 11 09:11:28 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Feb 11 09:11:28 volumio systemd[1]: shairport-sync.service: Consumed 2.270s CPU time.
Feb 11 09:11:28 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Feb 11 09:11:28 volumio sudo[5194]: pam_unix(sudo:session): session closed for user root
Feb 11 09:11:28 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver...
Feb 11 09:11:28 volumio volumio[4920]: info: CoreCommandRouter::volumioGetState
Feb 11 09:11:28 volumio volumio[4920]: info: CorePlayQueue::getTrack 0
Feb 11 09:11:28 volumio systemd[1]: shairport-sync.service: Deactivated successfully.
Feb 11 09:11:28 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Feb 11 09:11:28 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Feb 11 09:11:28 volumio sudo[5196]: pam_unix(sudo:session): session closed for user root
Feb 11 09:11:28 volumio volumio[4920]: info: Shairport-Sync Started
Feb 11 09:11:28 volumio volumio[4920]: Error adding Membership: Error: addMembership EINVAL
Feb 11 09:11:28 volumio sudo[5198]: pam_unix(sudo:session): session closed for user root
Feb 11 09:11:28 volumio volumio[4920]: info: Shairport-Sync Started
Feb 11 09:11:28 volumio volumio[4920]: info: Shairport-Sync Started
Feb 11 09:11:28 volumio volumio[4920]: 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 11 09:11:28 volumio volumio[4920]: info: Spotify Successfully logged in
Feb 11 09:11:28 volumio volumio[4920]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 11 09:11:28 volumio volumio[4920]: info: [1770775888828] CoreMusicLibrary::Adding element Spotify
Feb 11 09:11:28 volumio volumio[4920]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 11 09:11:28 volumio volumio[4920]: Cannot find translation for source YouTube Music
Feb 11 09:11:28 volumio volumio[4920]: Cannot find translation for source Spotify
Feb 11 09:11:29 volumio volumio[4920]: info: [yt-cast-receiver] DIAL server listening on port 8098
Feb 11 09:11:29 volumio volumio[4920]: info: CoreCommandRouter::volumioRetrievevolume
Feb 11 09:11:29 volumio volumio[4920]: info: VolumeController:: Volume=100 Mute =false
Feb 11 09:11:29 volumio volumio[4920]: info: CoreCommandRouter::volumioGetState
Feb 11 09:11:29 volumio volumio[4920]: info: CorePlayQueue::getTrack 0
Feb 11 09:11:29 volumio volumio[4920]: info: CoreStateMachine::pushState
Feb 11 09:11:29 volumio volumio[4920]: info: CorePlayQueue::getTrack 0
Feb 11 09:11:29 volumio volumio[4920]: info: CoreCommandRouter::volumioPushState
Feb 11 09:11:30 volumio volumio[4920]: info: go-librespot daemon successfully initialized
Feb 11 09:11:31 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1.
Feb 11 09:11:31 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 11 09:11:31 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 11 09:11:31 volumio go-librespot[5235]: go-librespot daemon starting...
Feb 11 09:11:31 volumio mpd[5138]: 2026-02-11T09:11:31 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg
Feb 11 09:11:31 volumio systemd[1]: Started mpd.service - Music Player Daemon.
Feb 11 09:11:31 volumio go-librespot[5236]: time="2026-02-11T09:11:31+07:00" level=info msg="running go-librespot 0.4.0"
Feb 11 09:11:31 volumio go-librespot[5236]: time="2026-02-11T09:11:31+07:00" level=debug msg="app state loaded"
Feb 11 09:11:31 volumio go-librespot[5236]: time="2026-02-11T09:11:31+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 11 09:11:31 volumio sudo[5109]: pam_unix(sudo:session): session closed for user root
Feb 11 09:11:31 volumio sudo[5098]: pam_unix(sudo:session): session closed for user root
Feb 11 09:11:31 volumio volumio[4920]: error: MPD error: The expression evaluated to a falsy value:
Feb 11 09:11:31 volumio volumio[4920]:   assert.ok(self.idling)
Feb 11 09:11:31 volumio volumio[4920]: error: The expression evaluated to a falsy value:
Feb 11 09:11:31 volumio volumio[4920]:   assert.ok(self.idling)
Feb 11 09:11:31 volumio volumio[4920]: info: MPD running with PID5138
Feb 11 09:11:31 volumio volumio[4920]:  ,establishing connection
Feb 11 09:11:31 volumio volumio[4920]: error: updateQueue error: null
Feb 11 09:11:31 volumio volumio[4920]: info: Completed starting Core Plugins
Feb 11 09:11:31 volumio volumio[4920]: info: -------------------------------------------
Feb 11 09:11:31 volumio volumio[4920]: info: -----    MyVolumio plugins startup     ----
Feb 11 09:11:31 volumio volumio[4920]: info: -------------------------------------------
Feb 11 09:11:31 volumio volumio[4920]: info: [MyVolumio PluginManager] Fetching plans data....
Feb 11 09:11:31 volumio volumio[4920]: error: updateQueue error: null
Feb 11 09:11:31 volumio go-librespot[5236]: time="2026-02-11T09:11: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 11 09:11:31 volumio go-librespot[5236]: time="2026-02-11T09:11: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 11 09:11:31 volumio go-librespot[5236]: time="2026-02-11T09:11: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 11 09:11:31 volumio go-librespot[5236]: time="2026-02-11T09:11:31+07:00" level=info msg="zeroconf server listening on port 44973"
Feb 11 09:11:31 volumio go-librespot[5236]: time="2026-02-11T09:11:31+07:00" level=debug msg="obtained new client token: AADZUP+6Ojh8SJq9R3EUuyoe/DZSdIklC/5htJ/iUWM0C3jmuvx69RX98el0C5X/l/R3KBToQ+FizHZDz6deOMftrNEfwQgRCJ4V0LikuuGLWWxM4DPb3eGbJ2lSr4hVro4roeSbON29kx6wfwZHfy+fXnxa3g9zuqreo4tqtIlO1GfR2KOnr1O3BD89HybXPOPHJdTPj6myuMdX0yzRFxpT4J6Oe6VWgnR4+kdusivQrWViKL5ckwi1BA=="
Feb 11 09:11:32 volumio go-librespot[5236]: time="2026-02-11T09:11:32+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 11 09:11:32 volumio go-librespot[5236]: time="2026-02-11T09:11:32+07:00" level=debug msg="completed keyexchange"
Feb 11 09:11:32 volumio go-librespot[5236]: time="2026-02-11T09:11:32+07:00" level=debug msg="completed challenge"
Feb 11 09:11:32 volumio go-librespot[5236]: time="2026-02-11T09:11:32+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 11 09:11:32 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 11 09:11:32 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 11 09:11:33 volumio volumio[4920]: info: Initializing connection to go-librespot Websocket
Feb 11 09:11:33 volumio volumio[4920]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 11 09:11:35 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2.
Feb 11 09:11:35 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 11 09:11:35 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 11 09:11:35 volumio go-librespot[5251]: go-librespot daemon starting...
Feb 11 09:11:35 volumio go-librespot[5252]: time="2026-02-11T09:11:35+07:00" level=info msg="running go-librespot 0.4.0"
Feb 11 09:11:35 volumio go-librespot[5252]: time="2026-02-11T09:11:35+07:00" level=debug msg="app state loaded"
Feb 11 09:11:35 volumio go-librespot[5252]: time="2026-02-11T09:11:35+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 11 09:11:35 volumio go-librespot[5252]: time="2026-02-11T09:11: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-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]"
Feb 11 09:11:35 volumio go-librespot[5252]: time="2026-02-11T09:11:35+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 11 09:11:35 volumio go-librespot[5252]: time="2026-02-11T09:11:35+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 11 09:11:35 volumio go-librespot[5252]: time="2026-02-11T09:11:35+07:00" level=info msg="zeroconf server listening on port 35939"
Feb 11 09:11:36 volumio go-librespot[5252]: time="2026-02-11T09:11:36+07:00" level=debug msg="obtained new client token: AADzi8d8bc0DwsB6Mjjy/N+PZkT5kpyyuhkcQInRK+8o/RhXpwZ+7trkNgD1AYhI5EQTfahs/u//xVDNUG8fyLRTxCrvnhEz2KNNfp9S3UbvtYvlzGJG7HxWx6CxPD3u0c467DaNOb8D5C70gcmQoiBAck/8DrntWXHisDWmGyNL7a8P8GLOaVDiD0e3v7eOhfgvLmR9U2XURMH+eA8vxnUpGubX5fS3Xk0JvOO/aJosvQD0BQ4hvb8="
Feb 11 09:11:36 volumio volumio[4920]: error: Failed LSINFO: Error:  [50@0] {lsinfo} No such directory
Feb 11 09:11:36 volumio go-librespot[5252]: time="2026-02-11T09:11:36+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 11 09:11:36 volumio go-librespot[5252]: time="2026-02-11T09:11:36+07:00" level=debug msg="completed keyexchange"
Feb 11 09:11:36 volumio go-librespot[5252]: time="2026-02-11T09:11:36+07:00" level=debug msg="completed challenge"
Feb 11 09:11:36 volumio go-librespot[5252]: time="2026-02-11T09:11: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 11 09:11:36 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 11 09:11:36 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 11 09:11:36 volumio volumio[4920]: info: Initializing connection to go-librespot Websocket
Feb 11 09:11:36 volumio volumio[4920]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 11 09:11:39 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3.
Feb 11 09:11:39 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 11 09:11:39 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 11 09:11:39 volumio go-librespot[5259]: go-librespot daemon starting...
Feb 11 09:11:39 volumio go-librespot[5260]: time="2026-02-11T09:11:39+07:00" level=info msg="running go-librespot 0.4.0"
Feb 11 09:11:39 volumio go-librespot[5260]: time="2026-02-11T09:11:39+07:00" level=debug msg="app state loaded"
Feb 11 09:11:39 volumio go-librespot[5260]: time="2026-02-11T09:11:39+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 11 09:11:39 volumio volumio[4920]: info: Initializing connection to go-librespot Websocket
Feb 11 09:11:39 volumio go-librespot[5260]: time="2026-02-11T09:11:39+07:00" level=debug msg="new websocket client"
Feb 11 09:11:40 volumio volumio[4920]: info: Connection to go-librespot Websocket established
Feb 11 09:11:40 volumio go-librespot[5260]: time="2026-02-11T09:11: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-gew4.spotify.com:80]"
Feb 11 09:11:40 volumio go-librespot[5260]: time="2026-02-11T09:11:40+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 11 09:11:40 volumio go-librespot[5260]: time="2026-02-11T09:11:40+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 11 09:11:40 volumio go-librespot[5260]: time="2026-02-11T09:11:40+07:00" level=info msg="zeroconf server listening on port 33693"
Feb 11 09:11:40 volumio volumio[4920]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium
Feb 11 09:11:40 volumio volumio[4920]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium
Feb 11 09:11:40 volumio volumio[4920]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium
Feb 11 09:11:40 volumio volumio[4920]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium
Feb 11 09:11:40 volumio volumio[4920]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium
Feb 11 09:11:40 volumio volumio[4920]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium
Feb 11 09:11:40 volumio volumio[4920]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium
Feb 11 09:11:40 volumio volumio[4920]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium
Feb 11 09:11:40 volumio volumio[4920]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium
Feb 11 09:11:40 volumio volumio[4920]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium
Feb 11 09:11:40 volumio volumio[4920]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium
Feb 11 09:11:40 volumio volumio[4920]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar
Feb 11 09:11:40 volumio volumio[4920]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar
Feb 11 09:11:40 volumio volumio[4920]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar
Feb 11 09:11:40 volumio volumio[4920]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar
Feb 11 09:11:40 volumio volumio[4920]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar
Feb 11 09:11:40 volumio volumio[4920]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar
Feb 11 09:11:40 volumio volumio[4920]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar
Feb 11 09:11:40 volumio volumio[4920]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar
Feb 11 09:11:40 volumio volumio[4920]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar
Feb 11 09:11:40 volumio volumio[4920]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar
Feb 11 09:11:40 volumio volumio[4920]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar
Feb 11 09:11:40 volumio volumio[4920]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso
Feb 11 09:11:40 volumio volumio[4920]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso
Feb 11 09:11:40 volumio volumio[4920]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso
Feb 11 09:11:40 volumio volumio[4920]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso
Feb 11 09:11:40 volumio volumio[4920]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso
Feb 11 09:11:40 volumio volumio[4920]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso
Feb 11 09:11:40 volumio volumio[4920]: info: Adding plugin bluetooth to MyMusic Plugins
Feb 11 09:11:40 volumio volumio[4920]: info: Adding plugin multiroom to MyMusic Plugins
Feb 11 09:11:40 volumio volumio[4920]: info: Adding plugin metavolumio to MyMusic Plugins
Feb 11 09:11:40 volumio volumio[4920]: info: Adding plugin cd_controller to MyMusic Plugins
Feb 11 09:11:40 volumio volumio[4920]: info: Adding plugin qobuzconnect to MyMusic Plugins
Feb 11 09:11:40 volumio volumio[4920]: info: Adding plugin smart_inputs to MyMusic Plugins
Feb 11 09:11:40 volumio volumio[4920]: info: Adding plugin tidalconnect to MyMusic Plugins
Feb 11 09:11:40 volumio volumio[4920]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"...
Feb 11 09:11:40 volumio go-librespot[5260]: time="2026-02-11T09:11:40+07:00" level=debug msg="obtained new client token: AACvyHr21zN6iuEp2XEFcxmyZcRtpY535XWKR6SGIGM7htnrXcif8+q/Ytu63Sse9if1WuV2dp7bLXzKBu5TErmQ3+QtwaULTnUOR1BuDptd9ZGneuHweKOn6e7hapGoD5wpakT6ooVMW8VYWSMzwUGIsWu+hRyYza7St959N3h3GAt2lgsH6T8mI2ass0lpf9vRPhoulNie+tODyN8nQdfHuSjwTcVGQEvHiH30WVJ6fyi0BZ7CL63Fkg=="
Feb 11 09:11:40 volumio go-librespot[5260]: time="2026-02-11T09:11:40+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 11 09:11:40 volumio go-librespot[5260]: time="2026-02-11T09:11:40+07:00" level=debug msg="completed keyexchange"
Feb 11 09:11:40 volumio go-librespot[5260]: time="2026-02-11T09:11:40+07:00" level=debug msg="completed challenge"
Feb 11 09:11:40 volumio go-librespot[5260]: time="2026-02-11T09:11: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 11 09:11:40 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 11 09:11:40 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 11 09:11:42 volumio volumio[4920]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded
Feb 11 09:11:42 volumio volumio[4920]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio
Feb 11 09:11:42 volumio volumio[4920]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 11 09:11:42 volumio volumio[4920]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 11 09:11:42 volumio volumio[4920]: info: Starting MyVolumio Remote Streaming Endpoints
Feb 11 09:11:42 volumio volumio[4920]: info: MyVolumio login type: Token
Feb 11 09:11:42 volumio volumio[4920]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started
Feb 11 09:11:42 volumio volumio[4920]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"...
Feb 11 09:11:43 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4.
Feb 11 09:11:43 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 11 09:11:43 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 11 09:11:43 volumio go-librespot[5283]: go-librespot daemon starting...
Feb 11 09:11:43 volumio go-librespot[5284]: time="2026-02-11T09:11:43+07:00" level=info msg="running go-librespot 0.4.0"
Feb 11 09:11:43 volumio go-librespot[5284]: time="2026-02-11T09:11:43+07:00" level=debug msg="app state loaded"
Feb 11 09:11:43 volumio go-librespot[5284]: time="2026-02-11T09:11:43+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 11 09:11:44 volumio volumio[4920]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded
Feb 11 09:11:44 volumio volumio[4920]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services
Feb 11 09:11:44 volumio volumio[4920]: info: Streaming services startup
Feb 11 09:11:44 volumio volumio[4920]: info: Starting Streaming Daemon
Feb 11 09:11:44 volumio sudo[5291]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service
Feb 11 09:11:44 volumio sudo[5291]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 11 09:11:44 volumio volumio[4920]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started
Feb 11 09:11:44 volumio sudo[5291]: pam_unix(sudo:session): session closed for user root
Feb 11 09:11:44 volumio volumio[4920]: info: Getting Spotify volume
Feb 11 09:11:44 volumio volumio[4920]: info: Connection to go-librespot Websocket closed
Feb 11 09:11:44 volumio volumio[4920]: error: Cannot start Volumio Streaming Daemon
Feb 11 09:11:44 volumio volumio[4920]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service
Feb 11 09:11:44 volumio volumio[4920]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found.
Feb 11 09:11:44 volumio volumio[4920]: 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 11 09:11:44 volumio go-librespot[5284]: time="2026-02-11T09:11: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 11 09:11:44 volumio go-librespot[5284]: time="2026-02-11T09:11: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 11 09:11:44 volumio go-librespot[5284]: time="2026-02-11T09:11: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 11 09:11:44 volumio volumio[4920]: info: CoreCommandRouter::volumioGetState
Feb 11 09:11:44 volumio volumio[4920]: info: CorePlayQueue::getTrack 0
Feb 11 09:11:44 volumio go-librespot[5284]: time="2026-02-11T09:11:44+07:00" level=info msg="zeroconf server listening on port 35179"
Feb 11 09:11:44 volumio volumio[4920]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100
Feb 11 09:11:44 volumio volumio[4920]: SPOTIFY: SPOTIFY VOLUME undefined
Feb 11 09:11:44 volumio volumio[4920]: SPOTIFY: VOLUMIO VOLUME 100
Feb 11 09:11:44 volumio volumio[4920]: info: Aligning Spotify Volume to Volumio Volume
Feb 11 09:11:44 volumio volumio[4920]: info: CoreCommandRouter::volumioGetState
Feb 11 09:11:44 volumio volumio[4920]: info: CorePlayQueue::getTrack 0
Feb 11 09:11:44 volumio volumio[4920]: info: Setting Spotify Volume from Volumio: 100
Feb 11 09:11:44 volumio go-librespot[5284]: time="2026-02-11T09:11:44+07:00" level=debug msg="obtained new client token: AABipWrPiMykKyREpsCvF2KZDMdW7saxn5kvEHjVjHh0wGjXlqAFrDJ34TUqmq1O0NWjxRUaHOqdoVQZRHBWaZNDKSsL3PYpAkZuuDr+8Bq83OTfJKeTMxCPhiQYf4j30rbUmXBNqryj+eHvh5dgaFzrjQxb8qiNMqlTGwOwUFc6X9ivEN1VI14K53a226RuR1EOqDAwXt3dgEroAy6F8MXhuxxR3q1fiDn+PHhSc6/cMzd/iWdlVhp1xA=="
Feb 11 09:11:44 volumio go-librespot[5284]: time="2026-02-11T09:11:44+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 11 09:11:44 volumio go-librespot[5284]: time="2026-02-11T09:11:44+07:00" level=debug msg="completed keyexchange"
Feb 11 09:11:44 volumio go-librespot[5284]: time="2026-02-11T09:11:44+07:00" level=debug msg="completed challenge"
Feb 11 09:11:45 volumio go-librespot[5284]: time="2026-02-11T09:11: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 11 09:11:45 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 11 09:11:45 volumio volumio[4920]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Feb 11 09:11:45 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 11 09:11:45 volumio volumio[4920]: Error: socket hang up
Feb 11 09:11:45 volumio volumio[4920]:     at connResetException (node:internal/errors:720:14)
Feb 11 09:11:45 volumio volumio[4920]:     at Socket.socketOnEnd (node:_http_client:519:23)
Feb 11 09:11:45 volumio volumio[4920]:     at Socket.emit (node:events:526:35)
Feb 11 09:11:45 volumio volumio[4920]:     at endReadableNT (node:internal/streams/readable:1376:12)
Feb 11 09:11:45 volumio volumio[4920]:     at process.processTicksAndRejections (node:internal/process/task_queues:82:21) {
Feb 11 09:11:45 volumio volumio[4920]:   code: 'ECONNRESET',
Feb 11 09:11:45 volumio volumio[4920]:   response: undefined
Feb 11 09:11:45 volumio volumio[4920]: }
Feb 11 09:11:45 volumio volumio[4920]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Feb 11 09:11:46 volumio sudo[5313]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-11 09:10'
Feb 11 09:11:46 volumio sudo[5313]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 11 09:11:46 volumio sudo[5313]: pam_unix(sudo:session): session closed for user root
Feb 11 09:11:47 volumio volumio-remote-updater[643]: [2026-02-11 09:11:47] [error] handle_read_frame error: websocketpp.transport:7 (End of File)
Feb 11 09:11:47 volumio volumio-remote-updater[643]: [2026-02-11 09:11:47] [disconnect] Disconnect close local:[1006,End of File] remote:[1006]
Feb 11 09:11:47 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE
Feb 11 09:11:47 volumio systemd[1]: volumio.service: Failed with result 'exit-code'.
Feb 11 09:11:47 volumio systemd[1]: volumio.service: Consumed 55.484s CPU time.
Feb 11 09:11:47 volumio systemd[1]: Started dynamicswap.service - dynamicswap service.
Feb 11 09:11:47 volumio systemd[1]: dynamicswap.service: Deactivated successfully.
Feb 11 09:11:47 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 11534.
Feb 11 09:11:47 volumio systemd[1]: Started dynamicswap.service - dynamicswap service.
Feb 11 09:11:47 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module.
Feb 11 09:11:47 volumio systemd[1]: volumio.service: Consumed 55.484s CPU time.
Feb 11 09:11:47 volumio systemd[1]: Started volumio.service - Volumio Backend Module.
Feb 11 09:11:47 volumio systemd[1]: dynamicswap.service: Deactivated successfully.
Feb 11 09:11:48 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5.
Feb 11 09:11:48 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 11 09:11:48 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 11 09:11:48 volumio go-librespot[5340]: go-librespot daemon starting...
Feb 11 09:11:48 volumio go-librespot[5341]: time="2026-02-11T09:11:48+07:00" level=info msg="running go-librespot 0.4.0"
Feb 11 09:11:48 volumio go-librespot[5341]: time="2026-02-11T09:11:48+07:00" level=debug msg="app state loaded"
Feb 11 09:11:48 volumio go-librespot[5341]: time="2026-02-11T09:11:48+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 11 09:11:48 volumio go-librespot[5341]: time="2026-02-11T09:11: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-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 11 09:11:48 volumio go-librespot[5341]: time="2026-02-11T09:11:48+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 11 09:11:48 volumio go-librespot[5341]: time="2026-02-11T09:11:48+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 11 09:11:48 volumio go-librespot[5341]: time="2026-02-11T09:11:48+07:00" level=info msg="zeroconf server listening on port 33671"
Feb 11 09:11:49 volumio go-librespot[5341]: time="2026-02-11T09:11:49+07:00" level=debug msg="obtained new client token: AACpCp8hJfpnPzDbvDr0hSTr9C3gABYsOtlpCF9+z6YXzqsoxc4p9RelB86dyOOtGT14TxjGOg16lQSKiSInm8z3PcmzGZJSf4jb5qDN0rsk2G6m58njdpaEctOmKh1pWW+fweIIZikPMygQD8ZAk9TysmViVk97ZfWNmQ1BBlp/VUa/0Lc4W/neFs8xNVxn0Co+k8//Ie/zDdgSquhIUaUZa45PlMq46TIKGJrFU8zQuwqrVZ/y7n4="
Feb 11 09:11:49 volumio go-librespot[5341]: time="2026-02-11T09:11:49+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 11 09:11:49 volumio go-librespot[5341]: time="2026-02-11T09:11:49+07:00" level=debug msg="completed keyexchange"
Feb 11 09:11:49 volumio go-librespot[5341]: time="2026-02-11T09:11:49+07:00" level=debug msg="completed challenge"
Feb 11 09:11:49 volumio go-librespot[5341]: time="2026-02-11T09:11: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 11 09:11:49 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 11 09:11:49 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 11 09:11:51 volumio volumio[5325]: info: -------------------------------------------
Feb 11 09:11:51 volumio volumio[5325]: info: -----            Volumio3              ----
Feb 11 09:11:51 volumio volumio[5325]: info: -------------------------------------------
Feb 11 09:11:51 volumio volumio[5325]: info: -----          System startup          ----
Feb 11 09:11:51 volumio volumio[5325]: info: -------------------------------------------
Feb 11 09:11:52 volumio volumio-remote-updater[643]: [2026-02-11 09:11:52] [connect] Successful connection
Feb 11 09:11:52 volumio volumio[5325]: info: MYVOLUMIO Environment detected
Feb 11 09:11:52 volumio volumio[5325]: info: Plugin folders cleanup
Feb 11 09:11:52 volumio volumio[5325]: info: Scanning into folder /volumio/app/plugins/
Feb 11 09:11:52 volumio volumio[5325]: info: Scanning category audio_interface
Feb 11 09:11:52 volumio volumio[5325]: info: Scanning category miscellanea
Feb 11 09:11:52 volumio volumio[5325]: info: Scanning category music_service
Feb 11 09:11:52 volumio volumio[5325]: info: Scanning category plugins.json
Feb 11 09:11:52 volumio volumio[5325]: info: Scanning category system_controller
Feb 11 09:11:52 volumio volumio[5325]: info: Scanning category user_interface
Feb 11 09:11:52 volumio volumio[5325]: info: Scanning into folder /data/plugins/
Feb 11 09:11:52 volumio volumio[5325]: info: Scanning category music_service
Feb 11 09:11:52 volumio volumio[5325]: info: Plugin folders cleanup completed
Feb 11 09:11:52 volumio volumio[5325]: info: -------------------------------------------
Feb 11 09:11:52 volumio volumio[5325]: info: -----      Core plugins startup        ----
Feb 11 09:11:52 volumio volumio[5325]: info: -------------------------------------------
Feb 11 09:11:52 volumio volumio[5325]: info: Loading plugins from folder /volumio/app/plugins/
Feb 11 09:11:52 volumio volumio[5325]: info: Adding plugin upnp to MyMusic Plugins
Feb 11 09:11:52 volumio volumio[5325]: info: Adding plugin airplay_emulation to MyMusic Plugins
Feb 11 09:11:52 volumio volumio[5325]: info: Adding plugin upnp_browser to MyMusic Plugins
Feb 11 09:11:52 volumio volumio[5325]: info: Loading plugins from folder /data/plugins/
Feb 11 09:11:52 volumio volumio[5325]: info: Loading plugin "system"...
Feb 11 09:11:52 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6.
Feb 11 09:11:52 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 11 09:11:52 volumio volumio[5325]: info: Loading plugin "appearance"...
Feb 11 09:11:52 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 11 09:11:52 volumio go-librespot[5358]: go-librespot daemon starting...
Feb 11 09:11:52 volumio go-librespot[5362]: time="2026-02-11T09:11:52+07:00" level=info msg="running go-librespot 0.4.0"
Feb 11 09:11:52 volumio go-librespot[5362]: time="2026-02-11T09:11:52+07:00" level=debug msg="app state loaded"
Feb 11 09:11:52 volumio go-librespot[5362]: time="2026-02-11T09:11:52+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 11 09:11:53 volumio go-librespot[5362]: time="2026-02-11T09:11:53+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 11 09:11:53 volumio go-librespot[5362]: time="2026-02-11T09:11:53+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 11 09:11:53 volumio go-librespot[5362]: time="2026-02-11T09:11:53+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 11 09:11:53 volumio go-librespot[5362]: time="2026-02-11T09:11:53+07:00" level=info msg="zeroconf server listening on port 41325"
Feb 11 09:11:53 volumio go-librespot[5362]: time="2026-02-11T09:11:53+07:00" level=debug msg="obtained new client token: AAC6Mf53o8gtrYUZAyGrLNsVP8OFuYDoeiUUFSa2GVhulLPtQotelMkCYRgq8MqwOdERDGmWQesi2ODN7pntlRjdHMYXE17b+AqOmKcLwqvA3ZjDcffcUFnEngSMwClbs+bYOOiJEjCSudYfw+Py8kbRWzfSEw4IvIU/ybV2+1jUrdz2/pT6maTH+hj4pOcf7PGO55zF+jr3tapHUDElobAp6OketsMB2Metu2Oz9gQfAuWxP5lpFWn7pQ=="
Feb 11 09:11:53 volumio go-librespot[5362]: time="2026-02-11T09:11:53+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 11 09:11:53 volumio go-librespot[5362]: time="2026-02-11T09:11:53+07:00" level=debug msg="connected to ap-gae2.spotify.com:443"
Feb 11 09:11:53 volumio go-librespot[5362]: time="2026-02-11T09:11:53+07:00" level=debug msg="completed keyexchange"
Feb 11 09:11:53 volumio go-librespot[5362]: time="2026-02-11T09:11:53+07:00" level=debug msg="completed challenge"
Feb 11 09:11:53 volumio go-librespot[5362]: time="2026-02-11T09:11: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 11 09:11:53 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 11 09:11:53 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 11 09:11:54 volumio volumio[5325]: info: Loading plugin "network"...
Feb 11 09:11:54 volumio volumio[5325]: info: Refreshing Cached IP Addresses
Feb 11 09:11:54 volumio sudo[5371]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Feb 11 09:11:54 volumio sudo[5371]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 11 09:11:54 volumio sudo[5373]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Feb 11 09:11:54 volumio sudo[5373]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 11 09:11:54 volumio volumio[5325]: info: Loading plugin "services"...
Feb 11 09:11:54 volumio sudo[5371]: pam_unix(sudo:session): session closed for user root
Feb 11 09:11:54 volumio volumio[5325]: info: Loading plugin "alsa_controller"...
Feb 11 09:11:54 volumio sudo[5373]: pam_unix(sudo:session): session closed for user root
Feb 11 09:11:54 volumio sudo[5380]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan
Feb 11 09:11:54 volumio sudo[5380]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 11 09:11:54 volumio volumio[5325]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Feb 11 09:11:54 volumio volumio[5325]: info: Loading plugin "wizard"...
Feb 11 09:11:54 volumio volumio[5325]: info: Loading plugin "networkfs"...
Feb 11 09:11:54 volumio volumio[5325]: info: Starting Udev Watcher for removable devices
Feb 11 09:11:54 volumio volumio[5325]: info: Ignoring mount for partition: boot
Feb 11 09:11:54 volumio volumio[5325]: info: Ignoring mount for partition: volumio
Feb 11 09:11:54 volumio volumio[5325]: info: Ignoring mount for partition: volumio_data
Feb 11 09:11:54 volumio volumio[5325]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Feb 11 09:11:54 volumio volumio[5325]: info: Loading plugin "volumio_command_line_client"...
Feb 11 09:11:54 volumio volumio[5325]: info: Loading plugin "upnp"...
Feb 11 09:11:54 volumio volumio[5325]: info: [1770775914948] Starting Upmpd Daemon
Feb 11 09:11:54 volumio volumio[5325]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Feb 11 09:11:54 volumio volumio[5325]: info: Loading plugin "my_music"...
Feb 11 09:11:54 volumio volumio[5325]: info: Loading plugin "mpd"...
Feb 11 09:11:55 volumio volumio[5325]: info: Loading plugin "upnp_browser"...
Feb 11 09:11:56 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7.
Feb 11 09:11:56 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 11 09:11:56 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 11 09:11:56 volumio go-librespot[5404]: go-librespot daemon starting...
Feb 11 09:11:56 volumio go-librespot[5405]: time="2026-02-11T09:11:56+07:00" level=info msg="running go-librespot 0.4.0"
Feb 11 09:11:56 volumio go-librespot[5405]: time="2026-02-11T09:11:56+07:00" level=debug msg="app state loaded"
Feb 11 09:11:56 volumio go-librespot[5405]: time="2026-02-11T09:11:56+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 11 09:11:57 volumio go-librespot[5405]: time="2026-02-11T09:11: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-gue1.spotify.com:443 ap-gew1.spotify.com:80]"
Feb 11 09:11:57 volumio go-librespot[5405]: time="2026-02-11T09:11:57+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 11 09:11:57 volumio go-librespot[5405]: time="2026-02-11T09:11:57+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 11 09:11:57 volumio sudo[5380]: pam_unix(sudo:session): session closed for user root
Feb 11 09:11:57 volumio go-librespot[5405]: time="2026-02-11T09:11:57+07:00" level=info msg="zeroconf server listening on port 43489"
Feb 11 09:11:57 volumio go-librespot[5405]: time="2026-02-11T09:11:57+07:00" level=debug msg="obtained new client token: AAB2CCSIkUDJNtFEf5MXm8KIJLCrqOR0Xvp/bmtZOH6RFCuOGS6vTgiRwNyJJZW/dPMHkyJFOuT0pguvjbc0wVZ0TrEikb5Ce/8BytTPd5DVDNmkazNUrEFS6PlYp39SnrM0dM/q/4R8CjVWhvMo/rQ+T4gTh1G5eV3hsyWa4fXG7FZOrG4941HAIb1NCKYYFLAFOX8brJN8g1LP0f2jJaEV/Vp/02tXk+ogXhtn9gDrqtGxvF0pEjtMYg=="
Feb 11 09:11:57 volumio go-librespot[5405]: time="2026-02-11T09:11:57+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 11 09:11:57 volumio go-librespot[5405]: time="2026-02-11T09:11:57+07:00" level=debug msg="completed keyexchange"
Feb 11 09:11:57 volumio go-librespot[5405]: time="2026-02-11T09:11:57+07:00" level=debug msg="completed challenge"
Feb 11 09:11:57 volumio go-librespot[5405]: time="2026-02-11T09:11: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 11 09:11:57 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 11 09:11:57 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 11 09:11:58 volumio volumio[5325]: info: Starting UPNP Browser
Feb 11 09:11:58 volumio volumio[5325]: info: Loading plugin "alarm-clock"...
Feb 11 09:11:58 volumio volumio[5325]: info: Loading plugin "airplay_emulation"...
Feb 11 09:11:58 volumio volumio[5325]: info: Starting Shairport Sync
Feb 11 09:11:58 volumio volumio[5325]: info: Loading plugin "last_100"...
Feb 11 09:11:58 volumio volumio[5325]: info: Loading plugin "webradio"...
Feb 11 09:11:59 volumio volumio[5325]: info: Loading plugin "i2s_dacs"...
Feb 11 09:11:59 volumio volumio[5325]: info: Loading plugin "volumiodiscovery"...
Feb 11 09:11:59 volumio volumio[5325]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Feb 11 09:11:59 volumio volumio[5325]: *** WARNING *** Please fix your application to use the native API of Avahi!
Feb 11 09:11:59 volumio node[5325]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Feb 11 09:11:59 volumio volumio[5325]: *** WARNING *** For more information see 
Feb 11 09:11:59 volumio volumio[5325]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Feb 11 09:11:59 volumio volumio[5325]: *** WARNING *** Please fix your application to use the native API of Avahi!
Feb 11 09:11:59 volumio volumio[5325]: *** WARNING *** For more information see 
Feb 11 09:11:59 volumio node[5325]: *** WARNING *** Please fix your application to use the native API of Avahi!
Feb 11 09:11:59 volumio node[5325]: *** WARNING *** For more information see 
Feb 11 09:11:59 volumio node[5325]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Feb 11 09:11:59 volumio node[5325]: *** WARNING *** Please fix your application to use the native API of Avahi!
Feb 11 09:11:59 volumio node[5325]: *** WARNING *** For more information see 
Feb 11 09:11:59 volumio volumio[5325]: info: Applying required configuration parameters for plugin volumiodiscovery
Feb 11 09:11:59 volumio volumio[5325]: info: Discovery: Started advertising with name: Volumio
Feb 11 09:11:59 volumio volumio[5325]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Feb 11 09:11:59 volumio volumio[5325]: info: Loading plugin "spop"...
Feb 11 09:12:01 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8.
Feb 11 09:12:01 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 11 09:12:01 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 11 09:12:01 volumio volumio[5325]: info: Loading plugin "ytcr"...
Feb 11 09:12:01 volumio go-librespot[5417]: go-librespot daemon starting...
Feb 11 09:12:01 volumio go-librespot[5418]: time="2026-02-11T09:12:01+07:00" level=info msg="running go-librespot 0.4.0"
Feb 11 09:12:01 volumio go-librespot[5418]: time="2026-02-11T09:12:01+07:00" level=debug msg="app state loaded"
Feb 11 09:12:01 volumio go-librespot[5418]: time="2026-02-11T09:12:01+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 11 09:12:01 volumio go-librespot[5418]: time="2026-02-11T09:12: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 11 09:12:01 volumio go-librespot[5418]: time="2026-02-11T09:12: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 11 09:12:01 volumio go-librespot[5418]: time="2026-02-11T09:12: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 11 09:12:01 volumio go-librespot[5418]: time="2026-02-11T09:12:01+07:00" level=info msg="zeroconf server listening on port 45775"
Feb 11 09:12:02 volumio go-librespot[5418]: time="2026-02-11T09:12:02+07:00" level=debug msg="obtained new client token: AAC1iYEKIePiqKDCCq1M/zcRMMYGyLxAsEm7erjBpbT2t78E3Mb6hxPsPvTc0Acv4Qi2ctgqTc3nMmDb89zvehi17t+uoHr9PfFRvIHnWNDqEwLaJYTUEx5pTWdlBs4nskTIF3uKP1eYhb7U6ANxwglEUjStT0G8mD8/F5tGavcs7EuPur+lOq7nBxwmcA8BYSfQfa6uxACOBdQooBI/rdxygdYnUIy909vs6AnkfkDwq45ozidsUXQ5Nw=="
Feb 11 09:12:02 volumio go-librespot[5418]: time="2026-02-11T09:12:02+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 11 09:12:02 volumio go-librespot[5418]: time="2026-02-11T09:12:02+07:00" level=debug msg="completed keyexchange"
Feb 11 09:12:02 volumio go-librespot[5418]: time="2026-02-11T09:12:02+07:00" level=debug msg="completed challenge"
Feb 11 09:12:02 volumio go-librespot[5418]: time="2026-02-11T09:12:02+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 11 09:12:02 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 11 09:12:02 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 11 09:12:03 volumio volumio[5325]: info: Loading plugin "ytmusic"...
Feb 11 09:12:04 volumio volumio-remote-updater[643]: [2026-02-11 09:12:04] [connect] Successful connection
Feb 11 09:12:04 volumio volumio[5325]: info: Loading plugin "outputs"...
Feb 11 09:12:04 volumio volumio[5325]: info: Loading plugin "albumart"...
Feb 11 09:12:04 volumio volumio[5325]: info: Plugin example_plugin is not enabled
Feb 11 09:12:05 volumio volumio[5325]: info: Loading plugin "inputs"...
Feb 11 09:12:05 volumio volumio[5325]: info: Loading plugin "updater_comm"...
Feb 11 09:12:05 volumio volumio[5325]: info: Plugin mpdemulation is not enabled
Feb 11 09:12:05 volumio volumio[5325]: info: Loading plugin "rest_api"...
Feb 11 09:12:05 volumio volumio[5325]: info: Loading plugin "websocket"...
Feb 11 09:12:05 volumio volumio[5325]: info: Starting Socket.io Server version 1.7.4
Feb 11 09:12:05 volumio volumio[5325]: info: Loading plugin "RoonBridge"...
Feb 11 09:12:05 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9.
Feb 11 09:12:05 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 11 09:12:05 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 11 09:12:05 volumio go-librespot[5450]: go-librespot daemon starting...
Feb 11 09:12:05 volumio go-librespot[5451]: time="2026-02-11T09:12:05+07:00" level=info msg="running go-librespot 0.4.0"
Feb 11 09:12:05 volumio go-librespot[5451]: time="2026-02-11T09:12:05+07:00" level=debug msg="app state loaded"
Feb 11 09:12:05 volumio go-librespot[5451]: time="2026-02-11T09:12:05+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 11 09:12:05 volumio volumio[5325]: info: Applying required configuration parameters for plugin RoonBridge
Feb 11 09:12:05 volumio volumio[5325]: info: Loading i18n strings for locale en
Feb 11 09:12:05 volumio volumio[5325]: Updating browse sources language
Feb 11 09:12:05 volumio volumio[5325]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 11 09:12:06 volumio go-librespot[5451]: time="2026-02-11T09:12: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 11 09:12:06 volumio go-librespot[5451]: time="2026-02-11T09:12:06+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 11 09:12:06 volumio go-librespot[5451]: time="2026-02-11T09:12:06+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 11 09:12:06 volumio go-librespot[5451]: time="2026-02-11T09:12:06+07:00" level=info msg="zeroconf server listening on port 36087"
Feb 11 09:12:06 volumio volumio[5440]: Forking 3 albumart workers
Feb 11 09:12:06 volumio volumio[5325]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Feb 11 09:12:06 volumio volumio[5325]: info: CoreCommandRouter::initPlayerControls
Feb 11 09:12:06 volumio volumio[5325]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 09:12:06 volumio volumio[5325]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 09:12:06 volumio volumio[5325]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 09:12:06 volumio volumio[5325]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 09:12:06 volumio volumio[5325]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 09:12:06 volumio volumio[5325]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 09:12:06 volumio volumio[5325]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 09:12:06 volumio volumio[5325]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 09:12:06 volumio volumio[5325]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Feb 11 09:12:06 volumio volumio[5325]: Express server listening on port 3000
Feb 11 09:12:06 volumio volumio[5325]:  [Metrics]  WebUI:  16s 198.86ms 
Feb 11 09:12:06 volumio go-librespot[5451]: time="2026-02-11T09:12:06+07:00" level=debug msg="obtained new client token: AAAPs/I798ShzrH+bse3iEWfSMAXjTz4lacqZLG4owWX1r3CvWxTH3GAo27hEmLIgpoLu90Y0kNe0rE82RcnEqRtBx3faJ0J1cJHoI6tgX7FT+QI66XmoejXi0LM640X/iC0ZxgYJrPKMLgzn2RkluaRtQOjiv37e3VlEC16AiOOLp1Es3rI79en5rkKVgIAJEgbo4ekdu8lB4oCJKLJYHDvgvaXFFCYkS91GQLnKMTy/MDDE8WMsCs="
Feb 11 09:12:06 volumio volumio[5325]: info: CoreStateMachine::resetVolumioState
Feb 11 09:12:06 volumio volumio[5325]: info: CoreStateMachine::getcurrentVolume
Feb 11 09:12:06 volumio volumio[5325]: info: CoreCommandRouter::volumioRetrievevolume
Feb 11 09:12:06 volumio go-librespot[5451]: time="2026-02-11T09:12:06+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 11 09:12:06 volumio go-librespot[5451]: time="2026-02-11T09:12:06+07:00" level=debug msg="completed keyexchange"
Feb 11 09:12:06 volumio go-librespot[5451]: time="2026-02-11T09:12:06+07:00" level=debug msg="completed challenge"
Feb 11 09:12:06 volumio sudo[5492]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Feb 11 09:12:06 volumio sudo[5492]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 11 09:12:06 volumio sudo[5494]:  volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Feb 11 09:12:06 volumio sudo[5492]: pam_unix(sudo:session): session closed for user root
Feb 11 09:12:06 volumio sudo[5494]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 11 09:12:06 volumio sudo[5494]: pam_unix(sudo:session): session closed for user root
Feb 11 09:12:06 volumio go-librespot[5451]: time="2026-02-11T09:12: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 11 09:12:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 11 09:12:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 11 09:12:06 volumio volumio[5325]: info: Volumio Network Manager: Network status updated: 1
Feb 11 09:12:06 volumio volumio[5325]: info: VolumeController:: Volume=100 Mute =false
Feb 11 09:12:06 volumio volumio[5325]: info: CoreStateMachine::pushState
Feb 11 09:12:06 volumio volumio[5325]: info: CorePlayQueue::getTrack 0
Feb 11 09:12:06 volumio volumio[5325]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Feb 11 09:12:06 volumio volumio[5325]: info: CoreCommandRouter::volumioPushState
Feb 11 09:12:06 volumio volumio[5325]: info: CoreStateMachine::updateTrackBlock
Feb 11 09:12:06 volumio volumio[5325]: info: CorePlayQueue::getTrackBlock
Feb 11 09:12:06 volumio volumio[5325]: info: CoreCommandRouter::volumioRetrievevolume
Feb 11 09:12:06 volumio volumio-remote-updater[643]: [2026-02-11 09:12:06] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770775924 101
Feb 11 09:12:07 volumio volumio[5325]: 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 11 09:12:07 volumio volumio[5325]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 11 09:12:07 volumio volumio[5325]: info: Reloading queue from file
Feb 11 09:12:07 volumio volumio[5325]: info: CoreStateMachine::setRepeat null single undefined
Feb 11 09:12:07 volumio volumio[5325]: info: CoreStateMachine::pushState
Feb 11 09:12:07 volumio volumio[5325]: info: CorePlayQueue::getTrack 0
Feb 11 09:12:07 volumio volumio[5325]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Feb 11 09:12:07 volumio volumio[5325]: info: CoreCommandRouter::volumioPushState
Feb 11 09:12:07 volumio volumio[5325]: info: CoreStateMachine::setRandom null
Feb 11 09:12:07 volumio volumio[5325]: info: CoreStateMachine::pushState
Feb 11 09:12:07 volumio volumio[5325]: info: CorePlayQueue::getTrack 0
Feb 11 09:12:07 volumio volumio[5325]: info: CoreCommandRouter::volumioPushState
Feb 11 09:12:07 volumio volumio[5325]: info: Setting Device type: Raspberry PI
Feb 11 09:12:07 volumio volumio[5325]: info: Completed loading Core Plugins
Feb 11 09:12:07 volumio volumio[5325]: info: Preparing to generate the ALSA configuration file
Feb 11 09:12:07 volumio volumio[5325]: info: VolumeController:: Volume=100 Mute =false
Feb 11 09:12:07 volumio volumio[5325]: info: CoreStateMachine::pushState
Feb 11 09:12:07 volumio volumio[5325]: info: CorePlayQueue::getTrack 0
Feb 11 09:12:07 volumio volumio[5325]: info: CoreCommandRouter::volumioPushState
Feb 11 09:12:07 volumio volumio[5325]: info: Asound.conf file unchanged, so no further update is needed
Feb 11 09:12:07 volumio volumio[5325]: info: Output device has changed, restarting MPD
Feb 11 09:12:07 volumio volumio[5325]: info: Output device has changed, restarting Shairport Sync
Feb 11 09:12:07 volumio sudo[5511]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service
Feb 11 09:12:07 volumio volumio[5325]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 09:12:07 volumio volumio[5325]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 11 09:12:07 volumio sudo[5511]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 11 09:12:07 volumio sudo[5513]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Feb 11 09:12:07 volumio sudo[5513]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 11 09:12:07 volumio sudo[5513]: pam_unix(sudo:session): session closed for user root
Feb 11 09:12:07 volumio sudo[5515]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Feb 11 09:12:07 volumio sudo[5515]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 11 09:12:07 volumio volumio[5325]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Feb 11 09:12:07 volumio volumio[5325]: info: ___________ START PLUGINS ___________
Feb 11 09:12:07 volumio volumio[5325]: info: ControllerMpd::onStart: Initializing MPD
Feb 11 09:12:07 volumio volumio[5325]: info: Creating MPD Configuration file
Feb 11 09:12:07 volumio sudo[5511]: pam_unix(sudo:session): session closed for user root
Feb 11 09:12:07 volumio systemd[1]: Stopping mpd.service - Music Player Daemon...
Feb 11 09:12:07 volumio volumio[5325]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Feb 11 09:12:07 volumio volumio[5325]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 11 09:12:07 volumio volumio[5325]: info: [1770775927710] CoreMusicLibrary::Adding element Media Servers
Feb 11 09:12:07 volumio volumio[5325]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 11 09:12:07 volumio sudo[5524]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Feb 11 09:12:07 volumio sudo[5524]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 11 09:12:07 volumio volumio[5325]: info: UPNP Browser: Client initialized successfully
Feb 11 09:12:07 volumio sudo[5524]: pam_unix(sudo:session): session closed for user root
Feb 11 09:12:07 volumio sudo[5526]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Feb 11 09:12:07 volumio sudo[5526]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 11 09:12:07 volumio systemd[1]: mpd.service: Deactivated successfully.
Feb 11 09:12:07 volumio systemd[1]: Stopped mpd.service - Music Player Daemon.
Feb 11 09:12:07 volumio systemd[1]: mpd.service: Consumed 7.249s CPU time.
Feb 11 09:12:07 volumio systemd[1]: mpd.socket: Deactivated successfully.
Feb 11 09:12:07 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket.
Feb 11 09:12:07 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket...
Feb 11 09:12:07 volumio volumio[5325]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 09:12:07 volumio volumio[5325]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 11 09:12:07 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket.
Feb 11 09:12:07 volumio systemd[1]: Starting mpd.service - Music Player Daemon...
Feb 11 09:12:07 volumio volumio[5325]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Feb 11 09:12:07 volumio volumio[5325]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 09:12:07 volumio volumio[5325]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 11 09:12:08 volumio systemd[1]: mpd.service: Deactivated successfully.
Feb 11 09:12:08 volumio systemd[1]: Stopped mpd.service - Music Player Daemon.
Feb 11 09:12:08 volumio systemd[1]: mpd.socket: Deactivated successfully.
Feb 11 09:12:08 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket.
Feb 11 09:12:08 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket...
Feb 11 09:12:08 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket.
Feb 11 09:12:08 volumio systemd[1]: Starting mpd.service - Music Player Daemon...
Feb 11 09:12:08 volumio volumio[5325]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Feb 11 09:12:08 volumio volumio[5325]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 11 09:12:08 volumio volumio[5325]: info: [1770775928105] CoreMusicLibrary::Adding element Last_100
Feb 11 09:12:08 volumio volumio[5325]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 11 09:12:08 volumio volumio[5325]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 11 09:12:08 volumio volumio[5325]: info: [1770775928114] CoreMusicLibrary::Adding element Webradio
Feb 11 09:12:08 volumio volumio[5325]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 11 09:12:08 volumio volumio[5325]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Feb 11 09:12:08 volumio volumio[5325]: info: Initializing BBC Radios
Feb 11 09:12:08 volumio volumio[5325]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Feb 11 09:12:08 volumio volumio[5325]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 11 09:12:08 volumio volumio[5325]: info: Creating Spotify config file
Feb 11 09:12:08 volumio volumio[5325]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 09:12:08 volumio sudo[5540]:     root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log
Feb 11 09:12:08 volumio sudo[5540]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
Feb 11 09:12:08 volumio sudo[5540]: pam_unix(sudo:session): session closed for user root
Feb 11 09:12:09 volumio volumio[5461]: Starting albumart workers
Feb 11 09:12:09 volumio volumio[5459]: Starting albumart workers
Feb 11 09:12:09 volumio volumio[5325]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 11 09:12:09 volumio volumio[5325]: info: [1770775929476] CoreMusicLibrary::Adding element YouTube Music
Feb 11 09:12:09 volumio volumio[5325]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 11 09:12:09 volumio volumio[5325]: Cannot find translation for source YouTube Music
Feb 11 09:12:09 volumio volumio[5325]: info: Volumio Calling Home
Feb 11 09:12:09 volumio sudo[5557]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service
Feb 11 09:12:09 volumio sudo[5557]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 11 09:12:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10.
Feb 11 09:12:09 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 11 09:12:09 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 11 09:12:09 volumio volumio[5460]: Starting albumart workers
Feb 11 09:12:09 volumio go-librespot[5562]: go-librespot daemon starting...
Feb 11 09:12:09 volumio sudo[5557]: pam_unix(sudo:session): session closed for user root
Feb 11 09:12:09 volumio go-librespot[5563]: time="2026-02-11T09:12:09+07:00" level=info msg="running go-librespot 0.4.0"
Feb 11 09:12:10 volumio volumio[5325]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7
Feb 11 09:12:10 volumio volumio[5325]: info: Discovery: Found device Volumio
Feb 11 09:12:10 volumio volumio[5325]: info: CoreCommandRouter::volumioGetState
Feb 11 09:12:10 volumio go-librespot[5563]: time="2026-02-11T09:12:10+07:00" level=info msg="zeroconf server listening on port 40013"
Feb 11 09:12:10 volumio volumio[5325]: info: CorePlayQueue::getTrack 0
Feb 11 09:12:10 volumio volumio[5325]: info: Discovery: this is already registered,  921648ed-0557-4d70-9927-1420682efcc7
Feb 11 09:12:10 volumio volumio[5325]: info: Discovery: Found device Volumio
Feb 11 09:12:10 volumio volumio[5325]: info: CoreCommandRouter::volumioGetState
Feb 11 09:12:10 volumio volumio[5325]: info: CorePlayQueue::getTrack 0
Feb 11 09:12:10 volumio volumio[5325]: info: MPD Permissions set
Feb 11 09:12:10 volumio volumio[5325]: info: MPD Permissions set
Feb 11 09:12:10 volumio volumio[5325]: info: Upmpdcli Daemon Started
Feb 11 09:12:10 volumio volumio[5325]: info: Spotify config file written
Feb 11 09:12:10 volumio volumio[5325]: 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 11 09:12:10 volumio volumio[5325]: info: Volumio called home
Feb 11 09:12:10 volumio sudo[5572]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service
Feb 11 09:12:10 volumio sudo[5572]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 11 09:12:10 volumio volumio[5325]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 09:12:10 volumio volumio[5325]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 09:12:10 volumio volumio[5325]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 09:12:10 volumio volumio[5325]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 09:12:10 volumio volumio[5325]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 09:12:10 volumio volumio[5325]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 09:12:10 volumio volumio[5325]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 09:12:10 volumio volumio[5325]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 09:12:11 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon...
Feb 11 09:12:11 volumio volumio[5325]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 11 09:12:11 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully.
Feb 11 09:12:11 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 11 09:12:11 volumio volumio[5325]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 09:12:11 volumio volumio[5325]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 09:12:11 volumio volumio[5325]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 09:12:11 volumio volumio[5325]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 09:12:11 volumio volumio[5325]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 09:12:11 volumio volumio[5325]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 09:12:11 volumio volumio[5325]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 09:12:11 volumio volumio[5325]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 09:12:11 volumio volumio[5325]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 09:12:11 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 11 09:12:11 volumio volumio[5325]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 11 09:12:11 volumio volumio[5325]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 09:12:11 volumio go-librespot[5579]: go-librespot daemon starting...
Feb 11 09:12:11 volumio sudo[5572]: pam_unix(sudo:session): session closed for user root
Feb 11 09:12:11 volumio volumio[5325]: info: No need to fix Spotify hosts
Feb 11 09:12:11 volumio go-librespot[5585]: time="2026-02-11T09:12:11+07:00" level=info msg="running go-librespot 0.4.0"
Feb 11 09:12:11 volumio go-librespot[5585]: time="2026-02-11T09:12:11+07:00" level=debug msg="app state loaded"
Feb 11 09:12:11 volumio go-librespot[5585]: time="2026-02-11T09:12:11+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 11 09:12:11 volumio go-librespot[5585]: time="2026-02-11T09:12:11+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 11 09:12:11 volumio go-librespot[5585]: time="2026-02-11T09:12:11+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 11 09:12:11 volumio go-librespot[5585]: time="2026-02-11T09:12:11+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 11 09:12:11 volumio go-librespot[5585]: time="2026-02-11T09:12:11+07:00" level=info msg="zeroconf server listening on port 38609"
Feb 11 09:12:12 volumio go-librespot[5585]: time="2026-02-11T09:12:12+07:00" level=debug msg="obtained new client token: AACltgRFR4E2+aRP5YxhgWpdT0Pk4az5SCYNBSNRtpja+SAcDShTCu0AB1te0wKRAtei3mWxGHnRmLWBPAe3YnGgln/NBggyQ23a8O6nbNnRJP/gUlLjPyKtDBApnPcR+jHqdsyNN4reUlpogU96ku2/og4vnnlobp2VnoE5eGIK4cQV8tgTAJklUpcXUgIA8DZ1BWWqPxveoTGqCMmCMDNjqY7UrWHnyy0fPnLjEzk5UM0WKBgPtYs="
Feb 11 09:12:12 volumio go-librespot[5585]: time="2026-02-11T09:12:12+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 11 09:12:12 volumio volumio[5325]: info: Starting Shairport Sync
Feb 11 09:12:12 volumio volumio[5325]: info: Starting Shairport Sync
Feb 11 09:12:12 volumio volumio[5325]: info: Starting Shairport Sync
Feb 11 09:12:12 volumio go-librespot[5585]: time="2026-02-11T09:12:12+07:00" level=debug msg="completed keyexchange"
Feb 11 09:12:12 volumio go-librespot[5585]: time="2026-02-11T09:12:12+07:00" level=debug msg="completed challenge"
Feb 11 09:12:12 volumio sudo[5614]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Feb 11 09:12:12 volumio sudo[5616]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Feb 11 09:12:12 volumio sudo[5616]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 11 09:12:12 volumio sudo[5612]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Feb 11 09:12:12 volumio sudo[5612]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 11 09:12:12 volumio sudo[5614]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 11 09:12:12 volumio go-librespot[5585]: time="2026-02-11T09:12:12+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 11 09:12:12 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 11 09:12:12 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 11 09:12:12 volumio volumio[5325]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------
Feb 11 09:12:12 volumio volumio[5325]: SPOTIFY: BQCGGGBxJDrWlDdd0Ou44oN5d5T_KK9-yZ9DXtrkqnck4w5dbMbhjDZVy_tALvMsKxdzYuK3wht3MicYq__o9VDnl0U3oZjuSWrDSLY-L5VVsBJoAGNavot_nqSPYxQezUwzIMcJX4qDpc7VgW1J8nfDZf9rdI7vMyYoqXtpjgMUbMdCR1XNyGSyQXPR8FYaVUIOV7SfjORWlK_HprvLAHOgua1ZrKfwLn9gTH7PVfNOWsBQwuDIBgmZ2GO0GupkkwtjsPyWJ6UgqzyBbDIfMshbcARj-IppN4iGCvPeawfkHO3_B9pHgied
Feb 11 09:12:12 volumio volumio[5325]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------
Feb 11 09:12:12 volumio volumio[5325]: info: New Spotify access token = BQCGGGBxJDrWlDdd0Ou44oN5d5T_KK9-yZ9DXtrkqnck4w5dbMbhjDZVy_tALvMsKxdzYuK3wht3MicYq__o9VDnl0U3oZjuSWrDSLY-L5VVsBJoAGNavot_nqSPYxQezUwzIMcJX4qDpc7VgW1J8nfDZf9rdI7vMyYoqXtpjgMUbMdCR1XNyGSyQXPR8FYaVUIOV7SfjORWlK_HprvLAHOgua1ZrKfwLn9gTH7PVfNOWsBQwuDIBgmZ2GO0GupkkwtjsPyWJ6UgqzyBbDIfMshbcARj-IppN4iGCvPeawfkHO3_B9pHgied
Feb 11 09:12:12 volumio volumio[5325]: info: Spotify credentials grant success - running version from March 24, 2019
Feb 11 09:12:12 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver...
Feb 11 09:12:12 volumio systemd[1]: shairport-sync.service: Deactivated successfully.
Feb 11 09:12:12 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Feb 11 09:12:12 volumio systemd[1]: shairport-sync.service: Consumed 2.340s CPU time.
Feb 11 09:12:12 volumio volumio[5325]: info: CoreCommandRouter::volumioGetState
Feb 11 09:12:12 volumio volumio[5325]: info: CorePlayQueue::getTrack 0
Feb 11 09:12:12 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Feb 11 09:12:12 volumio sudo[5612]: pam_unix(sudo:session): session closed for user root
Feb 11 09:12:12 volumio sudo[5614]: pam_unix(sudo:session): session closed for user root
Feb 11 09:12:12 volumio sudo[5616]: pam_unix(sudo:session): session closed for user root
Feb 11 09:12:13 volumio volumio[5325]: info: Shairport-Sync Started
Feb 11 09:12:13 volumio volumio[5325]: Error adding Membership: Error: addMembership EINVAL
Feb 11 09:12:13 volumio volumio[5325]: info: Shairport-Sync Started
Feb 11 09:12:13 volumio volumio[5325]: info: Shairport-Sync Started
Feb 11 09:12:13 volumio volumio[5325]: 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 11 09:12:13 volumio volumio[5325]: info: Spotify Successfully logged in
Feb 11 09:12:13 volumio volumio[5325]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 11 09:12:13 volumio volumio[5325]: info: [1770775933361] CoreMusicLibrary::Adding element Spotify
Feb 11 09:12:13 volumio volumio[5325]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 11 09:12:13 volumio volumio[5325]: Cannot find translation for source YouTube Music
Feb 11 09:12:13 volumio volumio[5325]: Cannot find translation for source Spotify
Feb 11 09:12:13 volumio volumio[5325]: info: [yt-cast-receiver] DIAL server listening on port 8098
Feb 11 09:12:13 volumio volumio[5325]: info: CoreCommandRouter::volumioRetrievevolume
Feb 11 09:12:14 volumio volumio[5325]: info: VolumeController:: Volume=100 Mute =false
Feb 11 09:12:14 volumio volumio[5325]: info: CoreCommandRouter::volumioGetState
Feb 11 09:12:14 volumio volumio[5325]: info: CorePlayQueue::getTrack 0
Feb 11 09:12:14 volumio volumio[5325]: info: CoreStateMachine::pushState
Feb 11 09:12:14 volumio volumio[5325]: info: CorePlayQueue::getTrack 0
Feb 11 09:12:14 volumio volumio[5325]: info: CoreCommandRouter::volumioPushState
Feb 11 09:12:15 volumio volumio[5325]: info: go-librespot daemon successfully initialized
Feb 11 09:12:15 volumio mpd[5555]: 2026-02-11T09:12:15 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg
Feb 11 09:12:15 volumio systemd[1]: Started mpd.service - Music Player Daemon.
Feb 11 09:12:15 volumio sudo[5515]: pam_unix(sudo:session): session closed for user root
Feb 11 09:12:15 volumio sudo[5526]: pam_unix(sudo:session): session closed for user root
Feb 11 09:12:15 volumio volumio[5325]: error: MPD error: The expression evaluated to a falsy value:
Feb 11 09:12:15 volumio volumio[5325]:   assert.ok(self.idling)
Feb 11 09:12:15 volumio volumio[5325]: error: The expression evaluated to a falsy value:
Feb 11 09:12:15 volumio volumio[5325]:   assert.ok(self.idling)
Feb 11 09:12:15 volumio volumio[5325]: error: updateQueue error: null
Feb 11 09:12:15 volumio volumio[5325]: info: MPD running with PID5555
Feb 11 09:12:15 volumio volumio[5325]:  ,establishing connection
Feb 11 09:12:15 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1.
Feb 11 09:12:15 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 11 09:12:15 volumio volumio[5325]: info: Completed starting Core Plugins
Feb 11 09:12:15 volumio volumio[5325]: info: -------------------------------------------
Feb 11 09:12:15 volumio volumio[5325]: info: -----    MyVolumio plugins startup     ----
Feb 11 09:12:15 volumio volumio[5325]: info: -------------------------------------------
Feb 11 09:12:15 volumio volumio[5325]: info: [MyVolumio PluginManager] Fetching plans data....
Feb 11 09:12:15 volumio volumio[5325]: error: updateQueue error: null
Feb 11 09:12:15 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 11 09:12:15 volumio go-librespot[5657]: go-librespot daemon starting...
Feb 11 09:12:15 volumio go-librespot[5658]: time="2026-02-11T09:12:15+07:00" level=info msg="running go-librespot 0.4.0"
Feb 11 09:12:15 volumio go-librespot[5658]: time="2026-02-11T09:12:15+07:00" level=debug msg="app state loaded"
Feb 11 09:12:15 volumio go-librespot[5658]: time="2026-02-11T09:12:15+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 11 09:12:16 volumio go-librespot[5658]: time="2026-02-11T09:12: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 11 09:12:16 volumio go-librespot[5658]: time="2026-02-11T09:12:16+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 11 09:12:16 volumio go-librespot[5658]: time="2026-02-11T09:12:16+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 11 09:12:16 volumio go-librespot[5658]: time="2026-02-11T09:12:16+07:00" level=info msg="zeroconf server listening on port 45529"
Feb 11 09:12:16 volumio go-librespot[5658]: time="2026-02-11T09:12:16+07:00" level=debug msg="obtained new client token: AADMMBj0JSl6x+HB6DcU1r7zDuY4Vo99DJ1tEbbLzv8zhRBFVQ8zruIFGjs6DsyWKaX48MFxc6kDzwiKsSybne00igxtG4Yw3JknnNe+HBlTG5YPon1TjVs+wa6QgBIh35EUfbfgdeGvK3Mwcw9rEW4FRGdEjUG1nV0T0Sab9HECjPah6yo8NWmo7fgVUJ1TZl8NtP8C8M85eQKjJ5J3CDbfL8COc1a4JWXlx+LrvfBL/kAEkLdtjWdUeA=="
Feb 11 09:12:16 volumio go-librespot[5658]: time="2026-02-11T09:12:16+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 11 09:12:16 volumio go-librespot[5658]: time="2026-02-11T09:12:16+07:00" level=debug msg="completed keyexchange"
Feb 11 09:12:16 volumio go-librespot[5658]: time="2026-02-11T09:12:16+07:00" level=debug msg="completed challenge"
Feb 11 09:12:16 volumio go-librespot[5658]: time="2026-02-11T09:12:16+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 11 09:12:16 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 11 09:12:16 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 11 09:12:18 volumio volumio[5325]: info: Initializing connection to go-librespot Websocket
Feb 11 09:12:18 volumio volumio[5325]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 11 09:12:20 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2.
Feb 11 09:12:20 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 11 09:12:20 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 11 09:12:20 volumio go-librespot[5665]: go-librespot daemon starting...
Feb 11 09:12:20 volumio go-librespot[5666]: time="2026-02-11T09:12:20+07:00" level=info msg="running go-librespot 0.4.0"
Feb 11 09:12:20 volumio go-librespot[5666]: time="2026-02-11T09:12:20+07:00" level=debug msg="app state loaded"
Feb 11 09:12:20 volumio go-librespot[5666]: time="2026-02-11T09:12:20+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 11 09:12:20 volumio volumio[5325]: error: Failed LSINFO: Error:  [50@0] {lsinfo} No such directory
Feb 11 09:12:20 volumio go-librespot[5666]: time="2026-02-11T09:12:20+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]"
Feb 11 09:12:20 volumio go-librespot[5666]: time="2026-02-11T09:12:20+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 11 09:12:20 volumio go-librespot[5666]: time="2026-02-11T09:12:20+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 11 09:12:20 volumio go-librespot[5666]: time="2026-02-11T09:12:20+07:00" level=info msg="zeroconf server listening on port 46569"
Feb 11 09:12:20 volumio go-librespot[5666]: time="2026-02-11T09:12:20+07:00" level=debug msg="obtained new client token: AACZJMoJhKO17M557texkdWkSyH25O+CDiW/qrmc0sf0sPMjLkyDT2EvJ80XLz5/N1T1ZdrJvOj8qHJ7LfyCic7uLPe6daZ+TamIocUpOtT6qGsRMCD8fQ+u+qHHToNUb4GT3K/wnuXAg7AstkB/R4wK5GDU4jkU8Ts1/pt0TxBM+hiGsfZ5OWB/AmKoTC4xgkY4ifuhlWXOyPr5FyRItIbzlbtG3geU38fTG4EBCkHTM3pemT0DIw1MQg=="
Feb 11 09:12:21 volumio go-librespot[5666]: time="2026-02-11T09:12:21+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 11 09:12:21 volumio go-librespot[5666]: time="2026-02-11T09:12:21+07:00" level=debug msg="completed keyexchange"
Feb 11 09:12:21 volumio go-librespot[5666]: time="2026-02-11T09:12:21+07:00" level=debug msg="completed challenge"
Feb 11 09:12:21 volumio go-librespot[5666]: time="2026-02-11T09:12: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 11 09:12:21 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 11 09:12:21 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 11 09:12:21 volumio volumio[5325]: info: Initializing connection to go-librespot Websocket
Feb 11 09:12:21 volumio volumio[5325]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 11 09:12:24 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3.
Feb 11 09:12:24 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 11 09:12:24 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 11 09:12:24 volumio go-librespot[5673]: go-librespot daemon starting...
Feb 11 09:12:24 volumio volumio[5325]: info: Initializing connection to go-librespot Websocket
Feb 11 09:12:24 volumio volumio[5325]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 11 09:12:24 volumio go-librespot[5674]: time="2026-02-11T09:12:24+07:00" level=info msg="running go-librespot 0.4.0"
Feb 11 09:12:24 volumio go-librespot[5674]: time="2026-02-11T09:12:24+07:00" level=debug msg="app state loaded"
Feb 11 09:12:24 volumio volumio[5325]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium
Feb 11 09:12:24 volumio volumio[5325]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium
Feb 11 09:12:24 volumio volumio[5325]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium
Feb 11 09:12:24 volumio volumio[5325]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium
Feb 11 09:12:24 volumio go-librespot[5674]: time="2026-02-11T09:12:24+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 11 09:12:24 volumio volumio[5325]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium
Feb 11 09:12:24 volumio volumio[5325]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium
Feb 11 09:12:24 volumio volumio[5325]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium
Feb 11 09:12:24 volumio volumio[5325]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium
Feb 11 09:12:24 volumio volumio[5325]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium
Feb 11 09:12:24 volumio volumio[5325]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium
Feb 11 09:12:24 volumio volumio[5325]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium
Feb 11 09:12:24 volumio volumio[5325]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar
Feb 11 09:12:24 volumio volumio[5325]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar
Feb 11 09:12:24 volumio volumio[5325]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar
Feb 11 09:12:24 volumio volumio[5325]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar
Feb 11 09:12:24 volumio volumio[5325]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar
Feb 11 09:12:24 volumio volumio[5325]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar
Feb 11 09:12:24 volumio volumio[5325]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar
Feb 11 09:12:24 volumio volumio[5325]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar
Feb 11 09:12:24 volumio volumio[5325]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar
Feb 11 09:12:24 volumio volumio[5325]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar
Feb 11 09:12:24 volumio volumio[5325]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar
Feb 11 09:12:24 volumio volumio[5325]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso
Feb 11 09:12:24 volumio volumio[5325]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso
Feb 11 09:12:24 volumio volumio[5325]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso
Feb 11 09:12:24 volumio volumio[5325]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso
Feb 11 09:12:24 volumio volumio[5325]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso
Feb 11 09:12:24 volumio volumio[5325]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso
Feb 11 09:12:24 volumio volumio[5325]: info: Adding plugin bluetooth to MyMusic Plugins
Feb 11 09:12:24 volumio volumio[5325]: info: Adding plugin multiroom to MyMusic Plugins
Feb 11 09:12:24 volumio volumio[5325]: info: Adding plugin metavolumio to MyMusic Plugins
Feb 11 09:12:24 volumio volumio[5325]: info: Adding plugin cd_controller to MyMusic Plugins
Feb 11 09:12:24 volumio volumio[5325]: info: Adding plugin qobuzconnect to MyMusic Plugins
Feb 11 09:12:24 volumio volumio[5325]: info: Adding plugin smart_inputs to MyMusic Plugins
Feb 11 09:12:24 volumio volumio[5325]: info: Adding plugin tidalconnect to MyMusic Plugins
Feb 11 09:12:24 volumio volumio[5325]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"...
Feb 11 09:12:24 volumio go-librespot[5674]: time="2026-02-11T09:12:24+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 11 09:12:24 volumio go-librespot[5674]: time="2026-02-11T09:12:24+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 11 09:12:24 volumio go-librespot[5674]: time="2026-02-11T09:12:24+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 11 09:12:24 volumio go-librespot[5674]: time="2026-02-11T09:12:24+07:00" level=info msg="zeroconf server listening on port 34207"
Feb 11 09:12:25 volumio go-librespot[5674]: time="2026-02-11T09:12:25+07:00" level=debug msg="obtained new client token: AABXWdIHejaH3Ljbv9HbKcgQDlOVNx1Ja7L2kP3ydWMzZUsCMSntbwV2nUnjH8PTA8nXlu+42MnueeeoHya1CCHlkKV3bt2EJiUmnh4OVdL50g0MueUjgpL8YK2I+t5/drAeIYtPONTcWPmPLa0OvR8amhMVr7UqBLi2H81apgf3f0cKZT0CQLfq9vODa9kpHJefC3I1GZZGtugeHDjZ8W2a9vgIaiR+uwwLTwf//GQ4xu3YpLk/01U="
Feb 11 09:12:25 volumio go-librespot[5674]: time="2026-02-11T09:12:25+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 11 09:12:25 volumio go-librespot[5674]: time="2026-02-11T09:12:25+07:00" level=debug msg="completed keyexchange"
Feb 11 09:12:25 volumio go-librespot[5674]: time="2026-02-11T09:12:25+07:00" level=debug msg="completed challenge"
Feb 11 09:12:25 volumio go-librespot[5674]: time="2026-02-11T09:12: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 11 09:12:25 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 11 09:12:25 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 11 09:12:26 volumio volumio[5325]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded
Feb 11 09:12:26 volumio volumio[5325]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio
Feb 11 09:12:26 volumio volumio[5325]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 11 09:12:26 volumio volumio[5325]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 11 09:12:26 volumio volumio[5325]: info: Starting MyVolumio Remote Streaming Endpoints
Feb 11 09:12:26 volumio volumio[5325]: info: MyVolumio login type: Token
Feb 11 09:12:26 volumio volumio[5325]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started
Feb 11 09:12:26 volumio volumio[5325]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"...
Feb 11 09:12:28 volumio volumio[5325]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded
Feb 11 09:12:28 volumio volumio[5325]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services
Feb 11 09:12:28 volumio volumio[5325]: info: Streaming services startup
Feb 11 09:12:28 volumio volumio[5325]: info: Starting Streaming Daemon
Feb 11 09:12:28 volumio sudo[5696]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service
Feb 11 09:12:28 volumio sudo[5696]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 11 09:12:28 volumio volumio[5325]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started
Feb 11 09:12:28 volumio sudo[5696]: pam_unix(sudo:session): session closed for user root
Feb 11 09:12:28 volumio volumio[5325]: info: Initializing connection to go-librespot Websocket
Feb 11 09:12:28 volumio volumio[5325]: error: Cannot start Volumio Streaming Daemon
Feb 11 09:12:28 volumio volumio[5325]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service
Feb 11 09:12:28 volumio volumio[5325]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found.
Feb 11 09:12:28 volumio volumio[5325]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 11 09:12:28 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4.
Feb 11 09:12:28 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 11 09:12:28 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 11 09:12:28 volumio go-librespot[5702]: go-librespot daemon starting...
Feb 11 09:12:28 volumio go-librespot[5703]: time="2026-02-11T09:12:28+07:00" level=info msg="running go-librespot 0.4.0"
Feb 11 09:12:28 volumio go-librespot[5703]: time="2026-02-11T09:12:28+07:00" level=debug msg="app state loaded"
Feb 11 09:12:28 volumio go-librespot[5703]: time="2026-02-11T09:12:28+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 11 09:12:29 volumio go-librespot[5703]: time="2026-02-11T09:12: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 11 09:12:29 volumio go-librespot[5703]: time="2026-02-11T09:12: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 11 09:12:29 volumio go-librespot[5703]: time="2026-02-11T09:12: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 11 09:12:29 volumio volumio[5325]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN
Feb 11 09:12:29 volumio go-librespot[5703]: time="2026-02-11T09:12:29+07:00" level=info msg="zeroconf server listening on port 35671"
Feb 11 09:12:29 volumio go-librespot[5703]: time="2026-02-11T09:12:29+07:00" level=debug msg="obtained new client token: AABLAf5FjLte2iZi/9+/4fvY/BHqtjdy4hlodsGcA7Lh/SdSLONvIZnMMj5eRsSlyikWItObsuyN5347NbMgK1i3FO8MP5wCgzE8PmzmXDuQGSgfjOqKcU8rmd3LcDp5o9M1+3VbPKHeog1Qvvz9uBHpinAavt3ahKmUY/Da9KOLgkabIA20S/hLM5Dol7wdO71zRD99a1YgV8mU0le/ipdZ20AOMeY07sQAypE5Vc7es4GsjTY6u2RRuw=="
Feb 11 09:12:29 volumio go-librespot[5703]: time="2026-02-11T09:12:29+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 11 09:12:29 volumio go-librespot[5703]: time="2026-02-11T09:12:29+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:443, retrying with a different AP" error="dial tcp 104.199.241.202:443: connect: connection refused"
Feb 11 09:12:29 volumio go-librespot[5703]: time="2026-02-11T09:12:29+07:00" level=debug msg="connected to ap-gae2.spotify.com:80"
Feb 11 09:12:29 volumio go-librespot[5703]: time="2026-02-11T09:12:29+07:00" level=debug msg="completed keyexchange"
Feb 11 09:12:29 volumio go-librespot[5703]: time="2026-02-11T09:12:29+07:00" level=debug msg="completed challenge"
Feb 11 09:12:29 volumio go-librespot[5703]: time="2026-02-11T09:12:29+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 11 09:12:29 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 11 09:12:29 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 11 09:12:29 volumio volumio[5325]: info: MyVolumio token set successfully
Feb 11 09:12:29 volumio volumio[5325]: info: MYVOLUMIO: Adding device
Feb 11 09:12:29 volumio volumio[5325]: info: MYVOLUMIO: Evaluating Server
Feb 11 09:12:30 volumio volumio[5325]: info: MyVolumio status changed
Feb 11 09:12:30 volumio volumio[5325]: info: Streaming services startup
Feb 11 09:12:30 volumio volumio[5325]: info: Starting Streaming Daemon
Feb 11 09:12:30 volumio volumio[5325]: info: Removing browser output: myVolumio user plan is not superstar
Feb 11 09:12:30 volumio volumio[5325]: info: Removing audio output:
Feb 11 09:12:30 volumio volumio[5325]: info: Stoppping Tunnel 1
Feb 11 09:12:30 volumio sudo[5732]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service
Feb 11 09:12:30 volumio sudo[5732]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 11 09:12:30 volumio sudo[5732]: pam_unix(sudo:session): session closed for user root
Feb 11 09:12:30 volumio sudo[5735]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service
Feb 11 09:12:30 volumio sudo[5735]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 11 09:12:30 volumio volumio[5325]: error: Cannot start Volumio Streaming Daemon
Feb 11 09:12:30 volumio volumio[5325]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service
Feb 11 09:12:30 volumio volumio[5325]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found.
Feb 11 09:12:30 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 11 09:12:30 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 11 09:12:30 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 11 09:12:30 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 11 09:12:30 volumio volumio[5325]: info: Setting Geolocation for MyVolumio to as1
Feb 11 09:12:30 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 11 09:12:30 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 11 09:12:30 volumio volumio[5325]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 11 09:12:30 volumio volumio[5325]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 11 09:12:30 volumio volumio[5325]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 11 09:12:30 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 11 09:12:30 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 11 09:12:30 volumio sudo[5735]: pam_unix(sudo:session): session closed for user root
Feb 11 09:12:30 volumio volumio[5325]: info: Remote SSH Stopped
Feb 11 09:12:31 volumio volumio[5325]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"}
Feb 11 09:12:31 volumio volumio[5325]: info: Initializing connection to go-librespot Websocket
Feb 11 09:12:31 volumio volumio[5325]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 11 09:12:31 volumio volumio[5325]: info: Updating MyVolumio device info
Feb 11 09:12:31 volumio volumio[5325]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 11 09:12:31 volumio volumio[5325]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 11 09:12:31 volumio volumio[5325]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 11 09:12:32 volumio volumio[5325]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"}
Feb 11 09:12:33 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5.
Feb 11 09:12:33 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 11 09:12:33 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 11 09:12:33 volumio go-librespot[5738]: go-librespot daemon starting...
Feb 11 09:12:33 volumio go-librespot[5739]: time="2026-02-11T09:12:33+07:00" level=info msg="running go-librespot 0.4.0"
Feb 11 09:12:33 volumio go-librespot[5739]: time="2026-02-11T09:12:33+07:00" level=debug msg="app state loaded"
Feb 11 09:12:33 volumio go-librespot[5739]: time="2026-02-11T09:12:33+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 11 09:12:33 volumio go-librespot[5739]: time="2026-02-11T09:12:33+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 11 09:12:33 volumio go-librespot[5739]: time="2026-02-11T09:12:33+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 11 09:12:33 volumio go-librespot[5739]: time="2026-02-11T09:12:33+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 11 09:12:33 volumio go-librespot[5739]: time="2026-02-11T09:12:33+07:00" level=info msg="zeroconf server listening on port 33763"
Feb 11 09:12:33 volumio go-librespot[5739]: time="2026-02-11T09:12:33+07:00" level=debug msg="obtained new client token: AAAuqilMDzHwS+6DZRsNGJmN7/wskqKZ6WvujhSwwEv8er/OR5tg85KHWgoYhtT47Dtai8sKizLz+N8GIFLf+tnvrTjuZM/oqir4BfMWvjb9LrqqXr/xlJr4b6ZMic+D5LSqI296vVCJWj4X5H5I01zuWeTos3Kr3k+0ynmXGf1HitVJZwxB3LFZ6UK5HQRXr0nnxN6OZP+mbkl1JaS6f1nBhSSHuCmLBa9Mp6Sp9DRI80jcISymrhddLQ=="
Feb 11 09:12:34 volumio go-librespot[5739]: time="2026-02-11T09:12:34+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 11 09:12:34 volumio go-librespot[5739]: time="2026-02-11T09:12:34+07:00" level=debug msg="completed keyexchange"
Feb 11 09:12:34 volumio go-librespot[5739]: time="2026-02-11T09:12:34+07:00" level=debug msg="completed challenge"
Feb 11 09:12:34 volumio go-librespot[5739]: time="2026-02-11T09:12: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 11 09:12:34 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 11 09:12:34 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 11 09:12:34 volumio volumio[5325]: info: Initializing connection to go-librespot Websocket
Feb 11 09:12:34 volumio volumio[5325]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 11 09:12:35 volumio volumio[5325]: info: MYVOLUMIO: Adding device
Feb 11 09:12:35 volumio volumio[5325]: info: MYVOLUMIO: Evaluating Server
Feb 11 09:12:36 volumio volumio[5325]: info: Setting Geolocation for MyVolumio to as1
Feb 11 09:12:36 volumio volumio[5325]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 11 09:12:36 volumio volumio[5325]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 11 09:12:36 volumio volumio[5325]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 11 09:12:37 volumio volumio[5325]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"}
Feb 11 09:12:37 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6.
Feb 11 09:12:37 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 11 09:12:37 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 11 09:12:37 volumio volumio[5325]: info: Initializing connection to go-librespot Websocket
Feb 11 09:12:37 volumio go-librespot[5779]: go-librespot daemon starting...
Feb 11 09:12:37 volumio volumio[5325]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 11 09:12:37 volumio go-librespot[5780]: time="2026-02-11T09:12:37+07:00" level=info msg="running go-librespot 0.4.0"
Feb 11 09:12:37 volumio go-librespot[5780]: time="2026-02-11T09:12:37+07:00" level=debug msg="app state loaded"
Feb 11 09:12:37 volumio go-librespot[5780]: time="2026-02-11T09:12:37+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 11 09:12:37 volumio volumio[5325]: info: Updating MyVolumio device info
Feb 11 09:12:37 volumio volumio[5325]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 11 09:12:37 volumio volumio[5325]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 11 09:12:37 volumio volumio[5325]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 11 09:12:37 volumio go-librespot[5780]: time="2026-02-11T09:12:37+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 11 09:12:37 volumio go-librespot[5780]: time="2026-02-11T09:12:37+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 11 09:12:37 volumio go-librespot[5780]: time="2026-02-11T09:12:37+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 11 09:12:37 volumio go-librespot[5780]: time="2026-02-11T09:12:37+07:00" level=info msg="zeroconf server listening on port 41179"
Feb 11 09:12:38 volumio volumio[5325]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"}
Feb 11 09:12:38 volumio go-librespot[5780]: time="2026-02-11T09:12:38+07:00" level=debug msg="obtained new client token: AACKowMtwE8u2fAXsu//iZBk8ji/32o2d5H/Faiji9k/SoN2oQ70o13ZJ6cPASaoIbTa/D4Fnz0d1Lyw+nxAc76KNjCPDyLpxHJJJ2y4DRD8DwaMTfyciu1pVnQVV/FkN3XkPBo3iWVTaOdv13jbctBLsKZo1O2fK7v3nuwm86z1hMbnrMBEy0PCH5aG22M7lOxdBAodXI+AQgZ8aUwyVz1ByBZMhdTjG9WmoBcEcQAbQQ9wWK3ClZU="
Feb 11 09:12:38 volumio go-librespot[5780]: time="2026-02-11T09:12:38+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 11 09:12:38 volumio go-librespot[5780]: time="2026-02-11T09:12:38+07:00" level=debug msg="completed keyexchange"
Feb 11 09:12:38 volumio go-librespot[5780]: time="2026-02-11T09:12:38+07:00" level=debug msg="completed challenge"
Feb 11 09:12:38 volumio go-librespot[5780]: time="2026-02-11T09:12:38+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 11 09:12:38 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 11 09:12:38 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 11 09:12:39 volumio volumio[5325]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Feb 11 09:12:39 volumio volumio[5325]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 11 09:12:39 volumio volumio[5325]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled
Feb 11 09:12:39 volumio volumio-remote-updater[643]: Test mode disabled
Feb 11 09:12:39 volumio volumio-remote-updater[643]: Alpha mode disabled
Feb 11 09:12:39 volumio volumio-remote-updater[643]: Alpha legacy test mode disabled
Feb 11 09:12:39 volumio volumio[5325]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled
Feb 11 09:12:40 volumio volumio[5325]: info: Update Ready: {"changeLogLink":"http://volumio.org","description":"FIXES
\n\nFix for CPU utilization spike
\nFix for triggerhappy input permission
\n
\nNEW ADDITIONS
\n\nAdd BLE onboarding plugin
\nEnable vc4-kms-v3d for all compatible RPi models
\nUpdate Tidal SDK
\n\n","title":"Update v4.096","updateavailable":true}
Feb 11 09:12:40 volumio volumio[5325]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache
Feb 11 09:12:40 volumio volumio[5325]: info: Initializing connection to go-librespot Websocket
Feb 11 09:12:40 volumio volumio[5325]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 11 09:12:41 volumio volumio[5325]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings
Feb 11 09:12:41 volumio volumio[5325]: 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 11 09:12:41 volumio volumio[5325]: info: CoreCommandRouter::volumioGetState
Feb 11 09:12:41 volumio volumio[5325]: info: CorePlayQueue::getTrack 0
Feb 11 09:12:41 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7.
Feb 11 09:12:41 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 11 09:12:41 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 11 09:12:41 volumio go-librespot[5791]: go-librespot daemon starting...
Feb 11 09:12:41 volumio go-librespot[5792]: time="2026-02-11T09:12:41+07:00" level=info msg="running go-librespot 0.4.0"
Feb 11 09:12:41 volumio go-librespot[5792]: time="2026-02-11T09:12:41+07:00" level=debug msg="app state loaded"
Feb 11 09:12:41 volumio go-librespot[5792]: time="2026-02-11T09:12:41+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 11 09:12:42 volumio go-librespot[5792]: time="2026-02-11T09:12:42+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 11 09:12:42 volumio go-librespot[5792]: time="2026-02-11T09:12:42+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 11 09:12:42 volumio go-librespot[5792]: time="2026-02-11T09:12:42+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 11 09:12:42 volumio go-librespot[5792]: time="2026-02-11T09:12:42+07:00" level=info msg="zeroconf server listening on port 43159"
Feb 11 09:12:42 volumio go-librespot[5792]: time="2026-02-11T09:12:42+07:00" level=debug msg="obtained new client token: AAAZ1j1SRyzZUDcvXV9n4NITtG5HSy56O8Zn7nbQ7IcM940J6vkP/7eXdQMTEPcYLN16YochORV2EgQN4VxoabsXprfNZ8OX0RQu8Zmrf68ZJA878+WoDgtJepzSsEiXX8tl1zpThZr7Irh4q0+5JmXyD2UKmwPtTyJwDSJXXPLG2jCdGJw89/0nSEZ3zYtJ44wlPZJ90eltFgAH3VypELLafgD2UhQvbcwhJQDaO1EQ9/lSKb2nFp9axA=="
Feb 11 09:12:42 volumio go-librespot[5792]: time="2026-02-11T09:12:42+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 11 09:12:42 volumio go-librespot[5792]: time="2026-02-11T09:12:42+07:00" level=debug msg="completed keyexchange"
Feb 11 09:12:42 volumio go-librespot[5792]: time="2026-02-11T09:12:42+07:00" level=debug msg="completed challenge"
Feb 11 09:12:42 volumio go-librespot[5792]: time="2026-02-11T09:12:42+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 11 09:12:42 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 11 09:12:42 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 11 09:12:43 volumio volumio[5325]: info: Initializing connection to go-librespot Websocket
Feb 11 09:12:43 volumio volumio[5325]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 11 09:12:45 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8.
Feb 11 09:12:45 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 11 09:12:45 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 11 09:12:45 volumio go-librespot[5814]: go-librespot daemon starting...
Feb 11 09:12:45 volumio go-librespot[5815]: time="2026-02-11T09:12:45+07:00" level=info msg="running go-librespot 0.4.0"
Feb 11 09:12:45 volumio go-librespot[5815]: time="2026-02-11T09:12:45+07:00" level=debug msg="app state loaded"
Feb 11 09:12:45 volumio go-librespot[5815]: time="2026-02-11T09:12:45+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 11 09:12:46 volumio volumio[5325]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 09:12:46 volumio volumio[5325]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 09:12:46 volumio volumio[5325]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam
Feb 11 09:12:46 volumio volumio[5325]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam
Feb 11 09:12:46 volumio volumio[5325]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam
Feb 11 09:12:46 volumio volumio[5325]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject
Feb 11 09:12:46 volumio volumio[5325]: info: CoreCommandRouter::volumioGetBrowseSources
Feb 11 09:12:46 volumio volumio[5325]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Feb 11 09:12:46 volumio volumio[5325]: info: Initializing connection to go-librespot Websocket
Feb 11 09:12:46 volumio go-librespot[5815]: time="2026-02-11T09:12:46+07:00" level=debug msg="new websocket client"
Feb 11 09:12:46 volumio volumio[5325]: info: Connection to go-librespot Websocket established
Feb 11 09:12:46 volumio go-librespot[5815]: time="2026-02-11T09:12:46+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 11 09:12:46 volumio go-librespot[5815]: time="2026-02-11T09:12:46+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 11 09:12:46 volumio go-librespot[5815]: time="2026-02-11T09:12:46+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 11 09:12:46 volumio go-librespot[5815]: time="2026-02-11T09:12:46+07:00" level=info msg="zeroconf server listening on port 41179"
Feb 11 09:12:46 volumio go-librespot[5815]: time="2026-02-11T09:12:46+07:00" level=debug msg="obtained new client token: AAA1sZI9s6I1HG2FiWKgZ9iB9IgwjRcFTSDboXrl74iSjT9699Nrilu6LlieiEz58l5JbQCsS3tN1eywyWmhVoATCkt0vfVcDjSfScUYdjZx/sImL4Fm/b0bJv6YqFdjahI3IOhpniluDLyMwDXQn0jehWRNiOjSP7H/5OIaCfODTiP+9ChSmy7i47otnNh9h1eU28AczIT/u0UhRh8agDikK3+UXjNUFOamA7fBuYArGPKTzYtUgop5zw=="
Feb 11 09:12:46 volumio go-librespot[5815]: time="2026-02-11T09:12:46+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 11 09:12:46 volumio go-librespot[5815]: time="2026-02-11T09:12:46+07:00" level=debug msg="completed keyexchange"
Feb 11 09:12:46 volumio go-librespot[5815]: time="2026-02-11T09:12:46+07:00" level=debug msg="completed challenge"
Feb 11 09:12:46 volumio go-librespot[5815]: time="2026-02-11T09:12:46+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Feb 11 09:12:47 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 11 09:12:47 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 11 09:12:47 volumio volumio[5325]: info: Connection to go-librespot Websocket closed
Feb 11 09:12:48 volumio volumio[5325]: error: MyVolumio Plugin failed to authenticate in a timely fashion
Feb 11 09:12:48 volumio volumio[5325]: info: Completed starting MyVolumio Plugin
Feb 11 09:12:48 volumio volumio[5325]:  [Metrics]  CommandRouter:  57s 197.71ms 
Feb 11 09:12:48 volumio volumio[5325]: info: CoreCommandRouter::volumiosetStartupVolume
Feb 11 09:12:48 volumio volumio[5325]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 09:12:48 volumio volumio[5325]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 11 09:12:48 volumio volumio[5325]: info: CoreCommandRouter::Close All Modals sent
Feb 11 09:12:48 volumio volumio[5325]: info: CoreCommandRouter::Close All Modals sent
Feb 11 09:12:49 volumio volumio[5325]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable
Feb 11 09:12:49 volumio volumio[5325]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus
Feb 11 09:12:49 volumio volumio[5325]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect
Feb 11 09:12:49 volumio volumio[5325]: info: Getting Spotify volume
Feb 11 09:12:49 volumio volumio[5325]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Feb 11 09:12:49 volumio volumio[5325]: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 11 09:12:49 volumio volumio[5325]:     at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) {
Feb 11 09:12:49 volumio volumio[5325]:   errno: -111,
Feb 11 09:12:49 volumio volumio[5325]:   code: 'ECONNREFUSED',
Feb 11 09:12:49 volumio volumio[5325]:   syscall: 'connect',
Feb 11 09:12:49 volumio volumio[5325]:   address: '127.0.0.1',
Feb 11 09:12:49 volumio volumio[5325]:   port: 9879,
Feb 11 09:12:49 volumio volumio[5325]:   response: undefined
Feb 11 09:12:49 volumio volumio[5325]: }
Feb 11 09:12:49 volumio volumio[5325]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Feb 11 09:12:50 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9.
Feb 11 09:12:50 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 11 09:12:50 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 11 09:12:50 volumio go-librespot[5836]: go-librespot daemon starting...
Feb 11 09:12:50 volumio go-librespot[5837]: time="2026-02-11T09:12:50+07:00" level=info msg="running go-librespot 0.4.0"
Feb 11 09:12:50 volumio go-librespot[5837]: time="2026-02-11T09:12:50+07:00" level=debug msg="app state loaded"
Feb 11 09:12:50 volumio go-librespot[5837]: time="2026-02-11T09:12:50+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 11 09:12:50 volumio go-librespot[5837]: time="2026-02-11T09:12:50+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 11 09:12:50 volumio go-librespot[5837]: time="2026-02-11T09:12:50+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 11 09:12:50 volumio go-librespot[5837]: time="2026-02-11T09:12:50+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 11 09:12:50 volumio go-librespot[5837]: time="2026-02-11T09:12:50+07:00" level=info msg="zeroconf server listening on port 45707"
Feb 11 09:12:50 volumio go-librespot[5837]: time="2026-02-11T09:12:50+07:00" level=debug msg="obtained new client token: AAAiKQvUHC3csNUBfzxhBIJ8heKa5m5gOg3Dy24hDitOYso8szR8WuuAiW3Y7xVMXYmC10CNiBKtUtg8UJ8WijowSNJbMzf/s0UOb4Y3I4zAg/a3pcBUdYDU+ZRORVnzCKzKe8b+4RjeSZdZV7ArOqZ5jV1l/fH49hHHfMqWKrcou0z3FOIJK3YLu/UH9e3kIRgwGgOoJGL5hRDPYHArRA1rg9iZZKl6tzJejqoAJVAbyN4E1O3ScSIpKA=="
Feb 11 09:12:50 volumio sudo[5846]:  volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-11 09:11'
Feb 11 09:12:50 volumio sudo[5846]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 11 09:12:51 volumio go-librespot[5837]: time="2026-02-11T09:12:51+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 11 09:12:51 volumio go-librespot[5837]: time="2026-02-11T09:12:51+07:00" level=debug msg="completed keyexchange"
Feb 11 09:12:51 volumio go-librespot[5837]: time="2026-02-11T09:12:51+07:00" level=debug msg="completed challenge"
Feb 11 09:12:51 volumio go-librespot[5837]: time="2026-02-11T09:12:51+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 11 09:12:51 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 11 09:12:51 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
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"