Feb 11 22:55:01 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15.
Feb 11 22:55:01 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 11 22:55:01 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 11 22:55:01 volumio go-librespot[23477]: go-librespot daemon starting...
Feb 11 22:55:01 volumio go-librespot[23478]: time="2026-02-11T22:55:01+07:00" level=info msg="running go-librespot 0.4.0"
Feb 11 22:55:01 volumio go-librespot[23478]: time="2026-02-11T22:55:01+07:00" level=debug msg="app state loaded"
Feb 11 22:55:01 volumio go-librespot[23478]: time="2026-02-11T22:55:01+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 11 22:55:01 volumio volumio[23462]: info: -------------------------------------------
Feb 11 22:55:01 volumio volumio[23462]: info: ----- Volumio3 ----
Feb 11 22:55:01 volumio volumio[23462]: info: -------------------------------------------
Feb 11 22:55:01 volumio volumio[23462]: info: ----- System startup ----
Feb 11 22:55:01 volumio volumio[23462]: info: -------------------------------------------
Feb 11 22:55:01 volumio go-librespot[23478]: time="2026-02-11T22:55: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-gew4.spotify.com:80]"
Feb 11 22:55:01 volumio go-librespot[23478]: time="2026-02-11T22:55:01+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 22:55:01 volumio go-librespot[23478]: time="2026-02-11T22:55:01+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 22:55:01 volumio go-librespot[23478]: time="2026-02-11T22:55:01+07:00" level=info msg="zeroconf server listening on port 36897"
Feb 11 22:55:01 volumio go-librespot[23478]: time="2026-02-11T22:55:01+07:00" level=debug msg="obtained new client token: AABx1gKSuOBaBc0SCI1af85kSGdRC6Z9zLk3ZeI9+d+UwuVQ2mmYw+2CMqAoJCEd09yJToV2c3g3XJgdkrxbH0dOfk21pTDIPX5UMdX/Nh3h2FO48Db2SyiymviqQwSw0bzUT7bGiG2ztBKLLUnuxRgr25+bcP+OaJqp5douDbJk+YCUurEvN6j9jiIMK2XC2UCieIW0/+lHRSGhya4hNH3S0+/dxO07iclST4vi+WwVmByfSnXD/Qc5vg=="
Feb 11 22:55:02 volumio go-librespot[23478]: time="2026-02-11T22:55:02+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 11 22:55:02 volumio go-librespot[23478]: time="2026-02-11T22:55:02+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF"
Feb 11 22:55:02 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 11 22:55:02 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 11 22:55:02 volumio volumio-remote-updater[643]: [2026-02-11 22:55:02] [connect] Successful connection
Feb 11 22:55:03 volumio volumio[23462]: info: MYVOLUMIO Environment detected
Feb 11 22:55:03 volumio volumio[23462]: info: Plugin folders cleanup
Feb 11 22:55:03 volumio volumio[23462]: info: Scanning into folder /volumio/app/plugins/
Feb 11 22:55:03 volumio volumio[23462]: info: Scanning category audio_interface
Feb 11 22:55:03 volumio volumio[23462]: info: Scanning category miscellanea
Feb 11 22:55:03 volumio volumio[23462]: info: Scanning category music_service
Feb 11 22:55:03 volumio volumio[23462]: info: Scanning category plugins.json
Feb 11 22:55:03 volumio volumio[23462]: info: Scanning category system_controller
Feb 11 22:55:03 volumio volumio[23462]: info: Scanning category user_interface
Feb 11 22:55:03 volumio volumio[23462]: info: Scanning into folder /data/plugins/
Feb 11 22:55:03 volumio volumio[23462]: info: Scanning category music_service
Feb 11 22:55:03 volumio volumio[23462]: info: Plugin folders cleanup completed
Feb 11 22:55:03 volumio volumio[23462]: info: -------------------------------------------
Feb 11 22:55:03 volumio volumio[23462]: info: ----- Core plugins startup ----
Feb 11 22:55:03 volumio volumio[23462]: info: -------------------------------------------
Feb 11 22:55:03 volumio volumio[23462]: info: Loading plugins from folder /volumio/app/plugins/
Feb 11 22:55:03 volumio volumio[23462]: info: Adding plugin upnp to MyMusic Plugins
Feb 11 22:55:03 volumio volumio[23462]: info: Adding plugin airplay_emulation to MyMusic Plugins
Feb 11 22:55:03 volumio volumio[23462]: info: Adding plugin upnp_browser to MyMusic Plugins
Feb 11 22:55:03 volumio volumio[23462]: info: Loading plugins from folder /data/plugins/
Feb 11 22:55:03 volumio volumio[23462]: info: Loading plugin "system"...
Feb 11 22:55:03 volumio volumio[23462]: info: Loading plugin "appearance"...
Feb 11 22:55:05 volumio volumio[23462]: info: Loading plugin "network"...
Feb 11 22:55:05 volumio volumio[23462]: info: Refreshing Cached IP Addresses
Feb 11 22:55:05 volumio sudo[23499]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Feb 11 22:55:05 volumio sudo[23499]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 11 22:55:05 volumio sudo[23501]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Feb 11 22:55:05 volumio sudo[23501]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 11 22:55:05 volumio sudo[23499]: pam_unix(sudo:session): session closed for user root
Feb 11 22:55:05 volumio volumio[23462]: info: Loading plugin "services"...
Feb 11 22:55:05 volumio volumio[23462]: info: Loading plugin "alsa_controller"...
Feb 11 22:55:05 volumio sudo[23501]: pam_unix(sudo:session): session closed for user root
Feb 11 22:55:05 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16.
Feb 11 22:55:05 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 11 22:55:05 volumio sudo[23506]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan
Feb 11 22:55:05 volumio sudo[23506]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 11 22:55:05 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 11 22:55:05 volumio go-librespot[23519]: go-librespot daemon starting...
Feb 11 22:55:05 volumio volumio[23462]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Feb 11 22:55:05 volumio go-librespot[23533]: time="2026-02-11T22:55:05+07:00" level=info msg="running go-librespot 0.4.0"
Feb 11 22:55:05 volumio go-librespot[23533]: time="2026-02-11T22:55:05+07:00" level=debug msg="app state loaded"
Feb 11 22:55:05 volumio volumio[23462]: info: Loading plugin "wizard"...
Feb 11 22:55:05 volumio go-librespot[23533]: time="2026-02-11T22:55:05+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 11 22:55:05 volumio volumio[23462]: info: Loading plugin "networkfs"...
Feb 11 22:55:05 volumio volumio[23462]: info: Starting Udev Watcher for removable devices
Feb 11 22:55:05 volumio volumio[23462]: info: Ignoring mount for partition: boot
Feb 11 22:55:05 volumio volumio[23462]: info: Ignoring mount for partition: volumio
Feb 11 22:55:05 volumio volumio[23462]: info: Ignoring mount for partition: volumio_data
Feb 11 22:55:05 volumio volumio[23462]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Feb 11 22:55:05 volumio volumio[23462]: info: Loading plugin "volumio_command_line_client"...
Feb 11 22:55:05 volumio volumio[23462]: info: Loading plugin "upnp"...
Feb 11 22:55:05 volumio volumio[23462]: info: [1770825305638] Starting Upmpd Daemon
Feb 11 22:55:05 volumio volumio[23462]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Feb 11 22:55:05 volumio volumio[23462]: info: Loading plugin "my_music"...
Feb 11 22:55:05 volumio volumio[23462]: info: Loading plugin "mpd"...
Feb 11 22:55:05 volumio go-librespot[23533]: time="2026-02-11T22:55:05+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 22:55:05 volumio go-librespot[23533]: time="2026-02-11T22:55:05+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 22:55:05 volumio go-librespot[23533]: time="2026-02-11T22:55:05+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 22:55:06 volumio go-librespot[23533]: time="2026-02-11T22:55:06+07:00" level=info msg="zeroconf server listening on port 43715"
Feb 11 22:55:06 volumio go-librespot[23533]: time="2026-02-11T22:55:06+07:00" level=debug msg="obtained new client token: AAD9jCHko/R8OiCl7Ts9Xo05RVzaQZujDXCDgubifkHTCXI775hl8dL+7CjcfQ/+tJLhyERu5m3Tb+wIbgTKXQV1KUYkRaE6IfBbHzonmBDZruiUUX9IXwUJ13QCdPhwAwB0O/s/hsfMHyaDYQExid6qtv20QyAJXWoLFgFG8788vUTBEO2Xfqdri30Nb0dTQNxzPVUrZCx9O0mxM/UINhdYyqYYePM9h3vGb8/OaXSO/4hajSLNva0="
Feb 11 22:55:06 volumio go-librespot[23533]: time="2026-02-11T22:55:06+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 11 22:55:06 volumio volumio[23462]: info: Loading plugin "upnp_browser"...
Feb 11 22:55:06 volumio go-librespot[23533]: time="2026-02-11T22:55:06+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF"
Feb 11 22:55:06 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 11 22:55:06 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 11 22:55:08 volumio sudo[23506]: pam_unix(sudo:session): session closed for user root
Feb 11 22:55:09 volumio volumio[23462]: info: Starting UPNP Browser
Feb 11 22:55:09 volumio volumio[23462]: info: Loading plugin "alarm-clock"...
Feb 11 22:55:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17.
Feb 11 22:55:09 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 11 22:55:09 volumio volumio[23462]: info: Loading plugin "airplay_emulation"...
Feb 11 22:55:09 volumio volumio[23462]: info: Starting Shairport Sync
Feb 11 22:55:09 volumio volumio[23462]: info: Loading plugin "last_100"...
Feb 11 22:55:09 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 11 22:55:09 volumio volumio[23462]: info: Loading plugin "webradio"...
Feb 11 22:55:09 volumio go-librespot[23542]: go-librespot daemon starting...
Feb 11 22:55:09 volumio go-librespot[23543]: time="2026-02-11T22:55:09+07:00" level=info msg="running go-librespot 0.4.0"
Feb 11 22:55:09 volumio go-librespot[23543]: time="2026-02-11T22:55:09+07:00" level=debug msg="app state loaded"
Feb 11 22:55:09 volumio go-librespot[23543]: time="2026-02-11T22:55:09+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 11 22:55:09 volumio volumio[23462]: info: Loading plugin "i2s_dacs"...
Feb 11 22:55:09 volumio volumio[23462]: info: Loading plugin "volumiodiscovery"...
Feb 11 22:55:09 volumio volumio[23462]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Feb 11 22:55:09 volumio volumio[23462]: *** WARNING *** Please fix your application to use the native API of Avahi!
Feb 11 22:55:09 volumio volumio[23462]: *** WARNING *** For more information see
Feb 11 22:55:09 volumio volumio[23462]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Feb 11 22:55:09 volumio volumio[23462]: *** WARNING *** Please fix your application to use the native API of Avahi!
Feb 11 22:55:09 volumio volumio[23462]: *** WARNING *** For more information see
Feb 11 22:55:09 volumio node[23462]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Feb 11 22:55:09 volumio node[23462]: *** WARNING *** Please fix your application to use the native API of Avahi!
Feb 11 22:55:09 volumio node[23462]: *** WARNING *** For more information see
Feb 11 22:55:09 volumio node[23462]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Feb 11 22:55:09 volumio node[23462]: *** WARNING *** Please fix your application to use the native API of Avahi!
Feb 11 22:55:09 volumio node[23462]: *** WARNING *** For more information see
Feb 11 22:55:09 volumio volumio[23462]: info: Applying required configuration parameters for plugin volumiodiscovery
Feb 11 22:55:09 volumio volumio[23462]: info: Discovery: Started advertising with name: Volumio
Feb 11 22:55:10 volumio volumio[23462]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Feb 11 22:55:10 volumio volumio[23462]: info: Loading plugin "spop"...
Feb 11 22:55:10 volumio go-librespot[23543]: time="2026-02-11T22:55:10+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 11 22:55:10 volumio go-librespot[23543]: time="2026-02-11T22:55:10+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 22:55:10 volumio go-librespot[23543]: time="2026-02-11T22:55:10+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 22:55:10 volumio go-librespot[23543]: time="2026-02-11T22:55:10+07:00" level=info msg="zeroconf server listening on port 45301"
Feb 11 22:55:10 volumio go-librespot[23543]: time="2026-02-11T22:55:10+07:00" level=debug msg="obtained new client token: AABhnr9sZ0oQEIeJMm7eR3UPIJf206NlIMB9U2r8J7K/0oF3dlNBsIHOqwNMRtg7f5iRxhShRokDUas+IDbHODOPOmScOWmEAiYEjko58vaZaoOh63GhB1pa15oKnVgexGKOc+noume6Wh9Yte3UygwZMxzyqSe0k9BJJ7N1t9FGe8nZyML6lIzAPJ9Jka/MBy5Y0Hp3HNXhlSSVPq0HvWDLJApYQJDw0PUqoQrQP8muXoPqreVklulMTQ=="
Feb 11 22:55:10 volumio go-librespot[23543]: time="2026-02-11T22:55:10+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 11 22:55:10 volumio go-librespot[23543]: time="2026-02-11T22:55:10+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF"
Feb 11 22:55:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 11 22:55:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 11 22:55:11 volumio volumio[23462]: info: Loading plugin "ytcr"...
Feb 11 22:55:13 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18.
Feb 11 22:55:13 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 11 22:55:13 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 11 22:55:13 volumio go-librespot[23552]: go-librespot daemon starting...
Feb 11 22:55:13 volumio go-librespot[23553]: time="2026-02-11T22:55:13+07:00" level=info msg="running go-librespot 0.4.0"
Feb 11 22:55:13 volumio go-librespot[23553]: time="2026-02-11T22:55:13+07:00" level=debug msg="app state loaded"
Feb 11 22:55:13 volumio go-librespot[23553]: time="2026-02-11T22:55:13+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 11 22:55:14 volumio go-librespot[23553]: time="2026-02-11T22:55:14+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 22:55:14 volumio go-librespot[23553]: time="2026-02-11T22:55:14+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 22:55:14 volumio go-librespot[23553]: time="2026-02-11T22:55:14+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 22:55:14 volumio go-librespot[23553]: time="2026-02-11T22:55:14+07:00" level=info msg="zeroconf server listening on port 42521"
Feb 11 22:55:14 volumio volumio[23462]: info: Loading plugin "ytmusic"...
Feb 11 22:55:14 volumio go-librespot[23553]: time="2026-02-11T22:55:14+07:00" level=debug msg="obtained new client token: AAAleBko+UBD+7zg12egp0K+cFEgq0kM89rPOLYBoSKPoa4YantWm5QgxPJzs8cqMdnf06TJixZYZ4ttbM3BRuiykKdW+sbd5nD6HzYO3u7NCYdlCOCcyEKkjxbfP0UNu2WEen9wkDqsw7pqOcHMIrtqOUaIBfAV3spgW0fcUt8MREtcVS9pTlL6G2CEbQX16cojY1fqcCBEMbE12vYZT+m74OPEUbrgDgKQY4rBStB/iRo7fNuhMDktcg=="
Feb 11 22:55:14 volumio go-librespot[23553]: time="2026-02-11T22:55:14+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 11 22:55:14 volumio go-librespot[23553]: time="2026-02-11T22:55:14+07:00" level=debug msg="completed keyexchange"
Feb 11 22:55:14 volumio go-librespot[23553]: time="2026-02-11T22:55:14+07:00" level=debug msg="completed challenge"
Feb 11 22:55:14 volumio go-librespot[23553]: time="2026-02-11T22:55:14+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Feb 11 22:55:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 11 22:55:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 11 22:55:15 volumio volumio-remote-updater[643]: [2026-02-11 22:55:15] [connect] Successful connection
Feb 11 22:55:15 volumio volumio[23462]: info: Loading plugin "outputs"...
Feb 11 22:55:15 volumio volumio[23462]: info: Loading plugin "albumart"...
Feb 11 22:55:15 volumio volumio[23462]: info: Plugin example_plugin is not enabled
Feb 11 22:55:15 volumio volumio[23462]: info: Loading plugin "inputs"...
Feb 11 22:55:15 volumio volumio[23462]: info: Loading plugin "updater_comm"...
Feb 11 22:55:15 volumio volumio[23462]: info: Plugin mpdemulation is not enabled
Feb 11 22:55:15 volumio volumio[23462]: info: Loading plugin "rest_api"...
Feb 11 22:55:15 volumio volumio[23462]: info: Loading plugin "websocket"...
Feb 11 22:55:15 volumio volumio[23462]: info: Starting Socket.io Server version 1.7.4
Feb 11 22:55:15 volumio volumio[23462]: info: Loading plugin "RoonBridge"...
Feb 11 22:55:16 volumio volumio[23462]: info: Applying required configuration parameters for plugin RoonBridge
Feb 11 22:55:16 volumio volumio[23462]: info: Loading i18n strings for locale en
Feb 11 22:55:16 volumio volumio[23462]: Updating browse sources language
Feb 11 22:55:16 volumio volumio[23462]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 11 22:55:16 volumio volumio[23574]: Forking 3 albumart workers
Feb 11 22:55:16 volumio volumio[23462]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Feb 11 22:55:16 volumio volumio[23462]: info: CoreCommandRouter::initPlayerControls
Feb 11 22:55:16 volumio volumio[23462]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 22:55:16 volumio volumio[23462]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 22:55:16 volumio volumio[23462]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 22:55:16 volumio volumio[23462]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 22:55:16 volumio volumio[23462]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 22:55:16 volumio volumio[23462]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 22:55:16 volumio volumio[23462]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 22:55:16 volumio volumio[23462]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 22:55:16 volumio volumio[23462]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Feb 11 22:55:16 volumio volumio[23462]: Express server listening on port 3000
Feb 11 22:55:16 volumio volumio[23462]: [Metrics] WebUI: 16s 169.51ms
Feb 11 22:55:16 volumio volumio[23462]: info: CoreStateMachine::resetVolumioState
Feb 11 22:55:16 volumio volumio[23462]: info: CoreStateMachine::getcurrentVolume
Feb 11 22:55:16 volumio volumio[23462]: info: CoreCommandRouter::volumioRetrievevolume
Feb 11 22:55:17 volumio sudo[23616]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Feb 11 22:55:17 volumio sudo[23616]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 11 22:55:17 volumio sudo[23619]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Feb 11 22:55:17 volumio sudo[23619]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 11 22:55:17 volumio sudo[23616]: pam_unix(sudo:session): session closed for user root
Feb 11 22:55:17 volumio sudo[23619]: pam_unix(sudo:session): session closed for user root
Feb 11 22:55:17 volumio volumio[23462]: info: Volumio Network Manager: Network status updated: 1
Feb 11 22:55:17 volumio volumio-remote-updater[643]: [2026-02-11 22:55:17] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770825315 101
Feb 11 22:55:17 volumio volumio[23462]: 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 22:55:17 volumio volumio[23462]: info: VolumeController:: Volume=100 Mute =false
Feb 11 22:55:17 volumio volumio[23462]: info: CoreStateMachine::pushState
Feb 11 22:55:17 volumio volumio[23462]: info: CorePlayQueue::getTrack 0
Feb 11 22:55:17 volumio volumio[23462]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Feb 11 22:55:17 volumio volumio[23462]: info: CoreCommandRouter::volumioPushState
Feb 11 22:55:17 volumio volumio[23462]: info: CoreStateMachine::updateTrackBlock
Feb 11 22:55:17 volumio volumio[23462]: info: CorePlayQueue::getTrackBlock
Feb 11 22:55:17 volumio volumio[23462]: info: CoreCommandRouter::volumioRetrievevolume
Feb 11 22:55:17 volumio volumio[23462]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 11 22:55:17 volumio volumio[23462]: info: Reloading queue from file
Feb 11 22:55:17 volumio volumio[23462]: info: CoreStateMachine::setRepeat null single undefined
Feb 11 22:55:17 volumio volumio[23462]: info: CoreStateMachine::pushState
Feb 11 22:55:17 volumio volumio[23462]: info: CorePlayQueue::getTrack 0
Feb 11 22:55:17 volumio volumio[23462]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Feb 11 22:55:17 volumio volumio[23462]: info: CoreCommandRouter::volumioPushState
Feb 11 22:55:17 volumio volumio[23462]: info: CoreStateMachine::setRandom null
Feb 11 22:55:17 volumio volumio[23462]: info: CoreStateMachine::pushState
Feb 11 22:55:17 volumio volumio[23462]: info: CorePlayQueue::getTrack 0
Feb 11 22:55:17 volumio volumio[23462]: info: CoreCommandRouter::volumioPushState
Feb 11 22:55:17 volumio volumio[23462]: info: Setting Device type: Raspberry PI
Feb 11 22:55:17 volumio volumio[23462]: info: Completed loading Core Plugins
Feb 11 22:55:17 volumio volumio[23462]: info: Preparing to generate the ALSA configuration file
Feb 11 22:55:17 volumio volumio[23462]: info: VolumeController:: Volume=100 Mute =false
Feb 11 22:55:17 volumio volumio[23462]: info: CoreStateMachine::pushState
Feb 11 22:55:17 volumio volumio[23462]: info: CorePlayQueue::getTrack 0
Feb 11 22:55:17 volumio volumio[23462]: info: CoreCommandRouter::volumioPushState
Feb 11 22:55:17 volumio volumio[23462]: info: Asound.conf file unchanged, so no further update is needed
Feb 11 22:55:17 volumio volumio[23462]: info: Output device has changed, restarting MPD
Feb 11 22:55:17 volumio sudo[23635]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service
Feb 11 22:55:17 volumio volumio[23462]: info: Output device has changed, restarting Shairport Sync
Feb 11 22:55:17 volumio sudo[23635]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 11 22:55:18 volumio volumio[23462]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 22:55:18 volumio volumio[23462]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 11 22:55:18 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 19.
Feb 11 22:55:18 volumio sudo[23640]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Feb 11 22:55:18 volumio sudo[23640]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 11 22:55:18 volumio sudo[23637]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Feb 11 22:55:18 volumio sudo[23637]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 11 22:55:18 volumio volumio[23462]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Feb 11 22:55:18 volumio volumio[23462]: info: ___________ START PLUGINS ___________
Feb 11 22:55:18 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 11 22:55:18 volumio sudo[23637]: pam_unix(sudo:session): session closed for user root
Feb 11 22:55:18 volumio volumio[23462]: info: ControllerMpd::onStart: Initializing MPD
Feb 11 22:55:18 volumio volumio[23462]: info: Creating MPD Configuration file
Feb 11 22:55:18 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 11 22:55:18 volumio go-librespot[23647]: go-librespot daemon starting...
Feb 11 22:55:18 volumio volumio[23462]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Feb 11 22:55:18 volumio volumio[23462]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 11 22:55:18 volumio volumio[23462]: info: [1770825318240] CoreMusicLibrary::Adding element Media Servers
Feb 11 22:55:18 volumio volumio[23462]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 11 22:55:18 volumio sudo[23635]: pam_unix(sudo:session): session closed for user root
Feb 11 22:55:18 volumio go-librespot[23650]: time="2026-02-11T22:55:18+07:00" level=info msg="running go-librespot 0.4.0"
Feb 11 22:55:18 volumio go-librespot[23650]: time="2026-02-11T22:55:18+07:00" level=debug msg="app state loaded"
Feb 11 22:55:18 volumio systemd[1]: Stopping mpd.service - Music Player Daemon...
Feb 11 22:55:18 volumio go-librespot[23650]: time="2026-02-11T22:55:18+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 11 22:55:18 volumio sudo[23649]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Feb 11 22:55:18 volumio sudo[23649]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 11 22:55:18 volumio sudo[23649]: pam_unix(sudo:session): session closed for user root
Feb 11 22:55:18 volumio sudo[23657]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Feb 11 22:55:18 volumio sudo[23657]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 11 22:55:18 volumio volumio[23462]: info: UPNP Browser: Client initialized successfully
Feb 11 22:55:18 volumio systemd[1]: mpd.service: Deactivated successfully.
Feb 11 22:55:18 volumio systemd[1]: Stopped mpd.service - Music Player Daemon.
Feb 11 22:55:18 volumio systemd[1]: mpd.service: Consumed 7.128s CPU time.
Feb 11 22:55:18 volumio systemd[1]: mpd.socket: Deactivated successfully.
Feb 11 22:55:18 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket.
Feb 11 22:55:18 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket...
Feb 11 22:55:18 volumio volumio[23462]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 22:55:18 volumio volumio[23462]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 11 22:55:18 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket.
Feb 11 22:55:18 volumio systemd[1]: Starting mpd.service - Music Player Daemon...
Feb 11 22:55:18 volumio volumio[23462]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Feb 11 22:55:18 volumio volumio[23462]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 22:55:18 volumio volumio[23462]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 11 22:55:18 volumio volumio[23462]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Feb 11 22:55:18 volumio volumio[23462]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 11 22:55:18 volumio volumio[23462]: info: [1770825318664] CoreMusicLibrary::Adding element Last_100
Feb 11 22:55:18 volumio volumio[23462]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 11 22:55:18 volumio volumio[23462]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 11 22:55:18 volumio volumio[23462]: info: [1770825318674] CoreMusicLibrary::Adding element Webradio
Feb 11 22:55:18 volumio volumio[23462]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 11 22:55:18 volumio volumio[23462]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Feb 11 22:55:18 volumio volumio[23462]: info: Initializing BBC Radios
Feb 11 22:55:18 volumio volumio[23462]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Feb 11 22:55:18 volumio volumio[23462]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 11 22:55:18 volumio volumio[23462]: info: Creating Spotify config file
Feb 11 22:55:18 volumio volumio[23462]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 22:55:19 volumio go-librespot[23650]: time="2026-02-11T22:55:19+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 22:55:19 volumio go-librespot[23650]: time="2026-02-11T22:55:19+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 22:55:19 volumio go-librespot[23650]: time="2026-02-11T22:55:19+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 22:55:19 volumio sudo[23666]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log
Feb 11 22:55:19 volumio sudo[23666]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
Feb 11 22:55:19 volumio go-librespot[23650]: time="2026-02-11T22:55:19+07:00" level=info msg="zeroconf server listening on port 44407"
Feb 11 22:55:19 volumio sudo[23666]: pam_unix(sudo:session): session closed for user root
Feb 11 22:55:19 volumio go-librespot[23650]: time="2026-02-11T22:55:19+07:00" level=debug msg="obtained new client token: AACt/RpGZZ9G6x8ipB7fFnxi9co9wkCev9EBGR1VrbwZc7LQGShUjgBoU+P1rgSF7/RyZOmSfKcGyEKIormBOb/B5/22bwZV/M2N457dJvQ11B72uLeU9LUuZ5ys+99t7sQ5L6HnpFDFVBZVXCHi7AaBqo3Gs179xs+f96E2t5d8VQjGTvstjFYrqiC6mhLHkLpAfC3JaWB4JL9X/oxwGhIUjcMQFfWcvkJ3DJZRvElYqqJbLdtHeS8ikg=="
Feb 11 22:55:19 volumio go-librespot[23650]: time="2026-02-11T22:55:19+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 11 22:55:19 volumio go-librespot[23650]: time="2026-02-11T22:55:19+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF"
Feb 11 22:55:19 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 11 22:55:19 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 11 22:55:20 volumio volumio[23584]: Starting albumart workers
Feb 11 22:55:20 volumio volumio[23462]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 11 22:55:20 volumio volumio[23462]: info: [1770825320268] CoreMusicLibrary::Adding element YouTube Music
Feb 11 22:55:20 volumio volumio[23462]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 11 22:55:20 volumio volumio[23462]: Cannot find translation for source YouTube Music
Feb 11 22:55:20 volumio volumio[23462]: info: Volumio Calling Home
Feb 11 22:55:20 volumio sudo[23689]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service
Feb 11 22:55:20 volumio sudo[23689]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 11 22:55:20 volumio sudo[23689]: pam_unix(sudo:session): session closed for user root
Feb 11 22:55:20 volumio volumio[23585]: Starting albumart workers
Feb 11 22:55:20 volumio volumio[23586]: Starting albumart workers
Feb 11 22:55:20 volumio volumio[23462]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7
Feb 11 22:55:20 volumio volumio[23462]: info: Discovery: Found device Volumio
Feb 11 22:55:20 volumio volumio[23462]: info: CoreCommandRouter::volumioGetState
Feb 11 22:55:20 volumio volumio[23462]: info: CorePlayQueue::getTrack 0
Feb 11 22:55:20 volumio volumio[23462]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7
Feb 11 22:55:20 volumio volumio[23462]: info: Discovery: Found device Volumio
Feb 11 22:55:20 volumio volumio[23462]: info: CoreCommandRouter::volumioGetState
Feb 11 22:55:20 volumio volumio[23462]: info: CorePlayQueue::getTrack 0
Feb 11 22:55:21 volumio volumio[23462]: info: MPD Permissions set
Feb 11 22:55:21 volumio volumio[23462]: info: MPD Permissions set
Feb 11 22:55:21 volumio volumio[23462]: info: Upmpdcli Daemon Started
Feb 11 22:55:21 volumio volumio[23462]: info: Spotify config file written
Feb 11 22:55:21 volumio sudo[23696]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service
Feb 11 22:55:21 volumio sudo[23696]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 11 22:55:21 volumio volumio[23462]: 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 22:55:21 volumio volumio[23462]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 22:55:21 volumio volumio[23462]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 22:55:21 volumio volumio[23462]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 22:55:21 volumio volumio[23462]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 22:55:21 volumio volumio[23462]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 22:55:21 volumio volumio[23462]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 22:55:21 volumio volumio[23462]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 22:55:21 volumio volumio[23462]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 22:55:21 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 11 22:55:21 volumio volumio[23462]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 11 22:55:21 volumio volumio[23462]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 22:55:21 volumio volumio[23462]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 22:55:21 volumio volumio[23462]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 22:55:21 volumio volumio[23462]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 22:55:21 volumio volumio[23462]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 22:55:21 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 11 22:55:21 volumio go-librespot[23700]: go-librespot daemon starting...
Feb 11 22:55:21 volumio volumio[23462]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 22:55:21 volumio volumio[23462]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 22:55:21 volumio volumio[23462]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 22:55:21 volumio volumio[23462]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 22:55:21 volumio sudo[23696]: pam_unix(sudo:session): session closed for user root
Feb 11 22:55:21 volumio go-librespot[23704]: time="2026-02-11T22:55:21+07:00" level=info msg="running go-librespot 0.4.0"
Feb 11 22:55:21 volumio go-librespot[23704]: time="2026-02-11T22:55:21+07:00" level=debug msg="app state loaded"
Feb 11 22:55:21 volumio go-librespot[23704]: time="2026-02-11T22:55:21+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 11 22:55:21 volumio volumio[23462]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 11 22:55:21 volumio volumio[23462]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 22:55:21 volumio volumio[23462]: info: No need to fix Spotify hosts
Feb 11 22:55:22 volumio volumio[23462]: info: Volumio called home
Feb 11 22:55:22 volumio go-librespot[23704]: time="2026-02-11T22:55:22+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]"
Feb 11 22:55:22 volumio go-librespot[23704]: time="2026-02-11T22:55:22+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]"
Feb 11 22:55:22 volumio go-librespot[23704]: time="2026-02-11T22:55:22+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]"
Feb 11 22:55:22 volumio go-librespot[23704]: time="2026-02-11T22:55:22+07:00" level=info msg="zeroconf server listening on port 42585"
Feb 11 22:55:22 volumio go-librespot[23704]: time="2026-02-11T22:55:22+07:00" level=debug msg="obtained new client token: AAD75duWx0tlVKApCMgkLsv+R7Qwf2sITqvdtCJLYtR4G2AVK7xbqvg41vclrR2xcqZPN7QbnIGoBkL6NudmzfLC4k59SpPrZokpVZ21CO3+FsGhqf9jaO8UWS65Of5d2Oumd9HkK9TaekM57jisys5RhF4Tzxwm5jdejNP/4bO1+QsR9cpmZnVZY0p3rSJWlrBOP+ePoC/8nQikmtzy72Acx4bXcG3xqIfJDFc65rzKwf53K0SE7hkh1A=="
Feb 11 22:55:22 volumio go-librespot[23704]: time="2026-02-11T22:55:22+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 11 22:55:22 volumio go-librespot[23704]: time="2026-02-11T22:55:22+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF"
Feb 11 22:55:22 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 11 22:55:22 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 11 22:55:23 volumio volumio[23462]: info: Starting Shairport Sync
Feb 11 22:55:23 volumio volumio[23462]: info: Starting Shairport Sync
Feb 11 22:55:23 volumio volumio[23462]: info: Starting Shairport Sync
Feb 11 22:55:23 volumio sudo[23736]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Feb 11 22:55:23 volumio sudo[23736]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 11 22:55:23 volumio sudo[23738]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Feb 11 22:55:23 volumio sudo[23738]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 11 22:55:23 volumio sudo[23740]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Feb 11 22:55:23 volumio sudo[23740]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 11 22:55:23 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver...
Feb 11 22:55:23 volumio systemd[1]: shairport-sync.service: Deactivated successfully.
Feb 11 22:55:23 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Feb 11 22:55:23 volumio systemd[1]: shairport-sync.service: Consumed 2.331s CPU time.
Feb 11 22:55:23 volumio volumio[23462]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------
Feb 11 22:55:23 volumio volumio[23462]: SPOTIFY: BQB3-60XdTseHVyK1Oz5pKSAqpjC51RcgAVQ31z3rqyumrrXc9NhG5ns5JFWW98hmDHMhYo9qDM_FxuIufpfr9Vgn3sz-9vXCzOwKMO1Qyk6F7G2Vvo3QbTQbGE7rVWSc5ZBucufZxE8b7ln0Nk6P-MyaDORQho4AuIBLvl_iUzxGe2Z9O-la3DLiWfmbhc5WvFFylPSO2nzCYQfbKYS5fH2Su-CBFa0DgFllV1IpDxo320fjMGK3_u0arZCr4mRGWHgf-oB8QHsB52UsA0VQpjKB9UBX0b0Q8xz0urtjKPfSRSUjGcrvm40
Feb 11 22:55:23 volumio volumio[23462]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------
Feb 11 22:55:23 volumio volumio[23462]: info: New Spotify access token = BQB3-60XdTseHVyK1Oz5pKSAqpjC51RcgAVQ31z3rqyumrrXc9NhG5ns5JFWW98hmDHMhYo9qDM_FxuIufpfr9Vgn3sz-9vXCzOwKMO1Qyk6F7G2Vvo3QbTQbGE7rVWSc5ZBucufZxE8b7ln0Nk6P-MyaDORQho4AuIBLvl_iUzxGe2Z9O-la3DLiWfmbhc5WvFFylPSO2nzCYQfbKYS5fH2Su-CBFa0DgFllV1IpDxo320fjMGK3_u0arZCr4mRGWHgf-oB8QHsB52UsA0VQpjKB9UBX0b0Q8xz0urtjKPfSRSUjGcrvm40
Feb 11 22:55:23 volumio volumio[23462]: info: Spotify credentials grant success - running version from March 24, 2019
Feb 11 22:55:23 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Feb 11 22:55:23 volumio sudo[23738]: pam_unix(sudo:session): session closed for user root
Feb 11 22:55:23 volumio sudo[23740]: pam_unix(sudo:session): session closed for user root
Feb 11 22:55:23 volumio sudo[23736]: pam_unix(sudo:session): session closed for user root
Feb 11 22:55:23 volumio volumio[23462]: info: CoreCommandRouter::volumioGetState
Feb 11 22:55:23 volumio volumio[23462]: info: CorePlayQueue::getTrack 0
Feb 11 22:55:23 volumio volumio[23462]: info: Shairport-Sync Started
Feb 11 22:55:23 volumio volumio[23462]: Error adding Membership: Error: addMembership EINVAL
Feb 11 22:55:23 volumio volumio[23462]: info: Shairport-Sync Started
Feb 11 22:55:23 volumio volumio[23462]: info: Shairport-Sync Started
Feb 11 22:55:24 volumio volumio[23462]: 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 22:55:24 volumio volumio[23462]: info: Spotify Successfully logged in
Feb 11 22:55:24 volumio volumio[23462]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 11 22:55:24 volumio volumio[23462]: info: [1770825324044] CoreMusicLibrary::Adding element Spotify
Feb 11 22:55:24 volumio volumio[23462]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 11 22:55:24 volumio volumio[23462]: Cannot find translation for source YouTube Music
Feb 11 22:55:24 volumio volumio[23462]: Cannot find translation for source Spotify
Feb 11 22:55:24 volumio volumio[23462]: info: [yt-cast-receiver] DIAL server listening on port 8098
Feb 11 22:55:24 volumio volumio[23462]: info: CoreCommandRouter::volumioRetrievevolume
Feb 11 22:55:24 volumio volumio[23462]: info: VolumeController:: Volume=100 Mute =false
Feb 11 22:55:24 volumio volumio[23462]: info: CoreCommandRouter::volumioGetState
Feb 11 22:55:24 volumio volumio[23462]: info: CorePlayQueue::getTrack 0
Feb 11 22:55:24 volumio volumio[23462]: info: CoreStateMachine::pushState
Feb 11 22:55:24 volumio volumio[23462]: info: CorePlayQueue::getTrack 0
Feb 11 22:55:24 volumio volumio[23462]: info: CoreCommandRouter::volumioPushState
Feb 11 22:55:26 volumio mpd[23687]: 2026-02-11T22:55:26 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg
Feb 11 22:55:26 volumio volumio[23462]: info: go-librespot daemon successfully initialized
Feb 11 22:55:26 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 20.
Feb 11 22:55:26 volumio systemd[1]: Started mpd.service - Music Player Daemon.
Feb 11 22:55:26 volumio sudo[23640]: pam_unix(sudo:session): session closed for user root
Feb 11 22:55:26 volumio sudo[23657]: pam_unix(sudo:session): session closed for user root
Feb 11 22:55:26 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 11 22:55:26 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 11 22:55:26 volumio go-librespot[23778]: go-librespot daemon starting...
Feb 11 22:55:26 volumio go-librespot[23781]: time="2026-02-11T22:55:26+07:00" level=info msg="running go-librespot 0.4.0"
Feb 11 22:55:26 volumio go-librespot[23781]: time="2026-02-11T22:55:26+07:00" level=debug msg="app state loaded"
Feb 11 22:55:26 volumio go-librespot[23781]: time="2026-02-11T22:55:26+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 11 22:55:26 volumio volumio[23462]: error: MPD error: The expression evaluated to a falsy value:
Feb 11 22:55:26 volumio volumio[23462]: assert.ok(self.idling)
Feb 11 22:55:26 volumio volumio[23462]: error: The expression evaluated to a falsy value:
Feb 11 22:55:26 volumio volumio[23462]: assert.ok(self.idling)
Feb 11 22:55:26 volumio volumio[23462]: info: MPD running with PID23687
Feb 11 22:55:26 volumio volumio[23462]: ,establishing connection
Feb 11 22:55:26 volumio volumio[23462]: error: updateQueue error: null
Feb 11 22:55:26 volumio volumio[23462]: info: Completed starting Core Plugins
Feb 11 22:55:26 volumio volumio[23462]: info: -------------------------------------------
Feb 11 22:55:26 volumio volumio[23462]: info: ----- MyVolumio plugins startup ----
Feb 11 22:55:26 volumio volumio[23462]: info: -------------------------------------------
Feb 11 22:55:26 volumio volumio[23462]: info: [MyVolumio PluginManager] Fetching plans data....
Feb 11 22:55:26 volumio volumio[23462]: error: updateQueue error: null
Feb 11 22:55:26 volumio go-librespot[23781]: time="2026-02-11T22:55:26+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 22:55:26 volumio go-librespot[23781]: time="2026-02-11T22:55:26+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 22:55:26 volumio go-librespot[23781]: time="2026-02-11T22:55:26+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 22:55:26 volumio go-librespot[23781]: time="2026-02-11T22:55:26+07:00" level=info msg="zeroconf server listening on port 35363"
Feb 11 22:55:26 volumio go-librespot[23781]: time="2026-02-11T22:55:26+07:00" level=debug msg="obtained new client token: AABeVvMG83IdJUE8lMoH6Z+psh0Wz9bpUk+2ATPHb3mA8QAQyPu9SNqihi/lLqVrBOzzLyrYlUp3Is7xcajBSWqqhHL0LgCvTfCZW4nQ9QvCQgF8EANASk4bVS/aiBMgvUa3iV1/gn/itd7mS6a1dMQwOxuYat951iVZmiD3kg001nmkm7rPy4MkbgRKgwKfkEvVxAzg9NH3VY9eX9kC4I5glBQQQVkSOy4xWkNf7egj8OJyrJVyCBMQIQ=="
Feb 11 22:55:27 volumio go-librespot[23781]: time="2026-02-11T22:55:27+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused"
Feb 11 22:55:27 volumio go-librespot[23781]: time="2026-02-11T22:55:27+07:00" level=debug msg="connected to ap-gae2.spotify.com:443"
Feb 11 22:55:27 volumio go-librespot[23781]: time="2026-02-11T22:55:27+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF"
Feb 11 22:55:27 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 11 22:55:27 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 11 22:55:29 volumio volumio[23462]: info: Initializing connection to go-librespot Websocket
Feb 11 22:55:29 volumio volumio[23462]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 11 22:55:30 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 21.
Feb 11 22:55:30 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 11 22:55:30 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 11 22:55:30 volumio go-librespot[23788]: go-librespot daemon starting...
Feb 11 22:55:30 volumio go-librespot[23789]: time="2026-02-11T22:55:30+07:00" level=info msg="running go-librespot 0.4.0"
Feb 11 22:55:30 volumio go-librespot[23789]: time="2026-02-11T22:55:30+07:00" level=debug msg="app state loaded"
Feb 11 22:55:30 volumio go-librespot[23789]: time="2026-02-11T22:55:30+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 11 22:55:30 volumio go-librespot[23789]: time="2026-02-11T22:55:30+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 22:55:30 volumio go-librespot[23789]: time="2026-02-11T22:55:30+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 22:55:30 volumio go-librespot[23789]: time="2026-02-11T22:55:30+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 22:55:30 volumio go-librespot[23789]: time="2026-02-11T22:55:30+07:00" level=info msg="zeroconf server listening on port 45541"
Feb 11 22:55:31 volumio go-librespot[23789]: time="2026-02-11T22:55:31+07:00" level=debug msg="obtained new client token: AAASGZAAbMbImOelmKzhlMOYb/8r0IX7y2NZ+n5aEC/E7el9LIEWXhpjvJZU3FmgA4kYkJngh8oYoxMRqZU3kDJnU5xA4fxVIMk1yEouUWS5+QcNxA4C0+ew8QbK+zUnewuKTXrdkmG0YVaiP2dungAHVXb05WjCseCobEozzxA8fN7uxIXlademtqYgjFfZX5eCvINUCXnFd3ci09dIigR4HF5bqoyiv29Xeztqjx5IWLJ4nQaLnTY="
Feb 11 22:55:31 volumio volumio[23462]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory
Feb 11 22:55:31 volumio go-librespot[23789]: time="2026-02-11T22:55:31+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 11 22:55:31 volumio go-librespot[23789]: time="2026-02-11T22:55:31+07:00" level=debug msg="completed keyexchange"
Feb 11 22:55:31 volumio go-librespot[23789]: time="2026-02-11T22:55:31+07:00" level=debug msg="completed challenge"
Feb 11 22:55:31 volumio go-librespot[23789]: time="2026-02-11T22:55:31+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Feb 11 22:55:31 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 11 22:55:31 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 11 22:55:32 volumio volumio[23462]: info: Initializing connection to go-librespot Websocket
Feb 11 22:55:32 volumio volumio[23462]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 11 22:55:34 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 22.
Feb 11 22:55:34 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 11 22:55:34 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 11 22:55:34 volumio go-librespot[23796]: go-librespot daemon starting...
Feb 11 22:55:34 volumio go-librespot[23797]: time="2026-02-11T22:55:34+07:00" level=info msg="running go-librespot 0.4.0"
Feb 11 22:55:34 volumio go-librespot[23797]: time="2026-02-11T22:55:34+07:00" level=debug msg="app state loaded"
Feb 11 22:55:34 volumio go-librespot[23797]: time="2026-02-11T22:55:34+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 11 22:55:34 volumio volumio[23462]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium
Feb 11 22:55:35 volumio volumio[23462]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium
Feb 11 22:55:35 volumio volumio[23462]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium
Feb 11 22:55:35 volumio volumio[23462]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium
Feb 11 22:55:35 volumio volumio[23462]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium
Feb 11 22:55:35 volumio volumio[23462]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium
Feb 11 22:55:35 volumio volumio[23462]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium
Feb 11 22:55:35 volumio volumio[23462]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium
Feb 11 22:55:35 volumio volumio[23462]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium
Feb 11 22:55:35 volumio volumio[23462]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium
Feb 11 22:55:35 volumio volumio[23462]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium
Feb 11 22:55:35 volumio volumio[23462]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar
Feb 11 22:55:35 volumio volumio[23462]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar
Feb 11 22:55:35 volumio volumio[23462]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar
Feb 11 22:55:35 volumio volumio[23462]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar
Feb 11 22:55:35 volumio volumio[23462]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar
Feb 11 22:55:35 volumio volumio[23462]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar
Feb 11 22:55:35 volumio volumio[23462]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar
Feb 11 22:55:35 volumio volumio[23462]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar
Feb 11 22:55:35 volumio volumio[23462]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar
Feb 11 22:55:35 volumio volumio[23462]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar
Feb 11 22:55:35 volumio volumio[23462]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar
Feb 11 22:55:35 volumio volumio[23462]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso
Feb 11 22:55:35 volumio volumio[23462]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso
Feb 11 22:55:35 volumio volumio[23462]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso
Feb 11 22:55:35 volumio volumio[23462]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso
Feb 11 22:55:35 volumio volumio[23462]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso
Feb 11 22:55:35 volumio volumio[23462]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso
Feb 11 22:55:35 volumio volumio[23462]: info: Adding plugin bluetooth to MyMusic Plugins
Feb 11 22:55:35 volumio volumio[23462]: info: Adding plugin multiroom to MyMusic Plugins
Feb 11 22:55:35 volumio volumio[23462]: info: Adding plugin metavolumio to MyMusic Plugins
Feb 11 22:55:35 volumio volumio[23462]: info: Adding plugin cd_controller to MyMusic Plugins
Feb 11 22:55:35 volumio volumio[23462]: info: Adding plugin qobuzconnect to MyMusic Plugins
Feb 11 22:55:35 volumio volumio[23462]: info: Adding plugin smart_inputs to MyMusic Plugins
Feb 11 22:55:35 volumio volumio[23462]: info: Adding plugin tidalconnect to MyMusic Plugins
Feb 11 22:55:35 volumio volumio[23462]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"...
Feb 11 22:55:35 volumio go-librespot[23797]: time="2026-02-11T22:55:35+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 11 22:55:35 volumio go-librespot[23797]: time="2026-02-11T22:55:35+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Feb 11 22:55:35 volumio go-librespot[23797]: time="2026-02-11T22:55:35+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Feb 11 22:55:35 volumio go-librespot[23797]: time="2026-02-11T22:55:35+07:00" level=info msg="zeroconf server listening on port 36951"
Feb 11 22:55:35 volumio go-librespot[23797]: time="2026-02-11T22:55:35+07:00" level=debug msg="obtained new client token: AAAwUrzmNuWpriKiwKtFGJR/4ZfGiNehtM0FMhGMKhk9uc8OSOrQLcwYiNHV+3vVLOp/3uupNuylJrr2wxOpB55SY4/IiOuKeG30bmu31CT/ZJ/qHI3r/8GYYRUThKaS/9xAgZASblCUK+NUc7VkxiIs7F7qw8D7Zsew8S7tMfTIXqfxB2vO1YYnVuJDPaHNreevH30eGB8M4HqLGzBe6bL3rD1p+35ZZ/vkQTYSZFcxv+hSrX9D1K1PKA=="
Feb 11 22:55:35 volumio go-librespot[23797]: time="2026-02-11T22:55:35+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 11 22:55:35 volumio go-librespot[23797]: time="2026-02-11T22:55:35+07:00" level=debug msg="completed keyexchange"
Feb 11 22:55:35 volumio go-librespot[23797]: time="2026-02-11T22:55:35+07:00" level=debug msg="completed challenge"
Feb 11 22:55:35 volumio go-librespot[23797]: time="2026-02-11T22:55:35+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 22:55:35 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 11 22:55:35 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 11 22:55:36 volumio volumio[23462]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded
Feb 11 22:55:36 volumio volumio[23462]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio
Feb 11 22:55:36 volumio volumio[23462]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 11 22:55:36 volumio volumio[23462]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 11 22:55:36 volumio volumio[23462]: info: Starting MyVolumio Remote Streaming Endpoints
Feb 11 22:55:36 volumio volumio[23462]: info: MyVolumio login type: Token
Feb 11 22:55:36 volumio volumio[23462]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started
Feb 11 22:55:36 volumio volumio[23462]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"...
Feb 11 22:55:38 volumio volumio[23462]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded
Feb 11 22:55:38 volumio volumio[23462]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services
Feb 11 22:55:38 volumio volumio[23462]: info: Streaming services startup
Feb 11 22:55:38 volumio volumio[23462]: info: Starting Streaming Daemon
Feb 11 22:55:38 volumio sudo[23820]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service
Feb 11 22:55:38 volumio sudo[23820]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 11 22:55:38 volumio volumio[23462]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started
Feb 11 22:55:38 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 23.
Feb 11 22:55:38 volumio sudo[23820]: pam_unix(sudo:session): session closed for user root
Feb 11 22:55:38 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 11 22:55:38 volumio volumio[23462]: info: Initializing connection to go-librespot Websocket
Feb 11 22:55:38 volumio volumio[23462]: error: Cannot start Volumio Streaming Daemon
Feb 11 22:55:38 volumio volumio[23462]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service
Feb 11 22:55:38 volumio volumio[23462]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found.
Feb 11 22:55:38 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 11 22:55:38 volumio go-librespot[23826]: go-librespot daemon starting...
Feb 11 22:55:38 volumio volumio[23462]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 11 22:55:38 volumio go-librespot[23828]: time="2026-02-11T22:55:38+07:00" level=info msg="running go-librespot 0.4.0"
Feb 11 22:55:38 volumio go-librespot[23828]: time="2026-02-11T22:55:38+07:00" level=debug msg="app state loaded"
Feb 11 22:55:38 volumio go-librespot[23828]: time="2026-02-11T22:55:38+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 11 22:55:39 volumio go-librespot[23828]: time="2026-02-11T22:55:39+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 22:55:39 volumio go-librespot[23828]: time="2026-02-11T22:55:39+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 22:55:39 volumio go-librespot[23828]: time="2026-02-11T22:55:39+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 22:55:39 volumio go-librespot[23828]: time="2026-02-11T22:55:39+07:00" level=info msg="zeroconf server listening on port 46201"
Feb 11 22:55:39 volumio go-librespot[23828]: time="2026-02-11T22:55:39+07:00" level=debug msg="obtained new client token: AAAmEqOa0oGhOjT70FrO/6Z6PxXEv7wB9BszRKEU17i2C6B2mhSAcEkyoXuvUOTRxA1jeWcPxp/3Sx73PxLtk42o4zryL40f7nihNeE/gZOyYaXNijRwN6010IpJIpJ7Q74NARRiDAU5FM3otkM+ORZxep+8LTHIilR+SbvNZr3sCfGwHL4JiBxMym3t2VPa5UAnQC+bju5ETD0SQ3/pFFneFlppMEXyaHffn4V/qgxQRcBNXKjRsQws8w=="
Feb 11 22:55:39 volumio go-librespot[23828]: time="2026-02-11T22:55:39+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 11 22:55:39 volumio go-librespot[23828]: time="2026-02-11T22:55:39+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF"
Feb 11 22:55:39 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 11 22:55:39 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 11 22:55:39 volumio volumio[23462]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN
Feb 11 22:55:41 volumio volumio[23462]: info: MyVolumio token set successfully
Feb 11 22:55:41 volumio volumio[23462]: info: MYVOLUMIO: Adding device
Feb 11 22:55:41 volumio volumio[23462]: info: MYVOLUMIO: Evaluating Server
Feb 11 22:55:42 volumio volumio[23462]: info: Initializing connection to go-librespot Websocket
Feb 11 22:55:42 volumio volumio[23462]: info: MyVolumio status changed
Feb 11 22:55:42 volumio volumio[23462]: info: Streaming services startup
Feb 11 22:55:42 volumio volumio[23462]: info: Starting Streaming Daemon
Feb 11 22:55:42 volumio volumio[23462]: info: Removing browser output: myVolumio user plan is not superstar
Feb 11 22:55:42 volumio volumio[23462]: info: Removing audio output:
Feb 11 22:55:42 volumio volumio[23462]: info: Stoppping Tunnel 1
Feb 11 22:55:42 volumio sudo[23856]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service
Feb 11 22:55:42 volumio sudo[23856]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 11 22:55:42 volumio sudo[23856]: pam_unix(sudo:session): session closed for user root
Feb 11 22:55:42 volumio volumio[23462]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 11 22:55:42 volumio volumio[23462]: error: Cannot start Volumio Streaming Daemon
Feb 11 22:55:42 volumio volumio[23462]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service
Feb 11 22:55:42 volumio volumio[23462]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found.
Feb 11 22:55:42 volumio sudo[23859]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service
Feb 11 22:55:42 volumio sudo[23859]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 11 22:55:42 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 22:55:42 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 22:55:42 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 22:55:42 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 22:55:42 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 22:55:42 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 22:55:42 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 22:55:42 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 22:55:42 volumio sudo[23859]: pam_unix(sudo:session): session closed for user root
Feb 11 22:55:42 volumio volumio[23462]: info: Remote SSH Stopped
Feb 11 22:55:43 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 24.
Feb 11 22:55:43 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 11 22:55:43 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 11 22:55:43 volumio go-librespot[23861]: go-librespot daemon starting...
Feb 11 22:55:43 volumio go-librespot[23862]: time="2026-02-11T22:55:43+07:00" level=info msg="running go-librespot 0.4.0"
Feb 11 22:55:43 volumio go-librespot[23862]: time="2026-02-11T22:55:43+07:00" level=debug msg="app state loaded"
Feb 11 22:55:43 volumio go-librespot[23862]: time="2026-02-11T22:55:43+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 11 22:55:43 volumio go-librespot[23862]: time="2026-02-11T22:55:43+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 11 22:55:43 volumio go-librespot[23862]: time="2026-02-11T22:55:43+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 22:55:43 volumio go-librespot[23862]: time="2026-02-11T22:55:43+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 22:55:43 volumio go-librespot[23862]: time="2026-02-11T22:55:43+07:00" level=info msg="zeroconf server listening on port 39951"
Feb 11 22:55:43 volumio go-librespot[23862]: time="2026-02-11T22:55:43+07:00" level=debug msg="obtained new client token: AAAggNGKPNiTNSivJ4cWM8SFaWNWoRlnX1wz6SBhQNqNUdx6knZ3ZCWYjTXobAzuyGNPcQj1XSGhTChazV7HncNcm5bGaHxDaYAfcjZLQLGOTfLQdTI5ANag3THpq97J5vW0wOHSygInfBnit6OYaQkLrzSEBQIKx2JSknRqJ3euZMp6Fat7nw/VCNXMcKDuBXqgMFJCOJ7DSztYW4zKtbHKEyzVicYXOKKdmMsYuDn3b4QHHl6VgaDkSA=="
Feb 11 22:55:43 volumio go-librespot[23862]: time="2026-02-11T22:55:43+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 11 22:55:44 volumio go-librespot[23862]: time="2026-02-11T22:55:44+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF"
Feb 11 22:55:44 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 11 22:55:44 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 11 22:55:44 volumio volumio[23462]: info: Setting Geolocation for MyVolumio to as1
Feb 11 22:55:44 volumio volumio[23462]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 11 22:55:44 volumio volumio[23462]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 11 22:55:44 volumio volumio[23462]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 11 22:55:45 volumio volumio[23462]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"}
Feb 11 22:55:45 volumio volumio[23462]: info: Updating MyVolumio device info
Feb 11 22:55:45 volumio volumio[23462]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 11 22:55:45 volumio volumio[23462]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 11 22:55:45 volumio volumio[23462]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 11 22:55:45 volumio volumio[23462]: info: Initializing connection to go-librespot Websocket
Feb 11 22:55:45 volumio volumio[23462]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 11 22:55:45 volumio volumio[23462]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"}
Feb 11 22:55:47 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 25.
Feb 11 22:55:47 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 11 22:55:47 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 11 22:55:47 volumio go-librespot[23883]: go-librespot daemon starting...
Feb 11 22:55:47 volumio go-librespot[23884]: time="2026-02-11T22:55:47+07:00" level=info msg="running go-librespot 0.4.0"
Feb 11 22:55:47 volumio go-librespot[23884]: time="2026-02-11T22:55:47+07:00" level=debug msg="app state loaded"
Feb 11 22:55:47 volumio go-librespot[23884]: time="2026-02-11T22:55:47+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 11 22:55:47 volumio go-librespot[23884]: time="2026-02-11T22:55:47+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]"
Feb 11 22:55:47 volumio go-librespot[23884]: time="2026-02-11T22:55:47+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 22:55:47 volumio go-librespot[23884]: time="2026-02-11T22:55:47+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 22:55:47 volumio go-librespot[23884]: time="2026-02-11T22:55:47+07:00" level=info msg="zeroconf server listening on port 37893"
Feb 11 22:55:48 volumio go-librespot[23884]: time="2026-02-11T22:55:48+07:00" level=debug msg="obtained new client token: AABWpAFEP2UalbFwL9htkhSekyLN3SaucM86U+KTq6qWRbK3A7t3ybfUFD7vGjonkOiI+hbn4XHazZuFYCeze9zfLjvAMnakp8TO8bpckGwqfNL1huvGc887pNhuAAZg2ctKLCcLJSu31wvx8yxqcYyv+pE4nxfKYEikJJCwaLkSEF2w7j3kZwvDUXncXJKbhv8FdGtl22J6TG+/biMWNJ2ZXYXrvXxH6TP39kDK7DeKVrz4XEqvmC8="
Feb 11 22:55:48 volumio go-librespot[23884]: time="2026-02-11T22:55:48+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 11 22:55:48 volumio volumio[23462]: info: Initializing connection to go-librespot Websocket
Feb 11 22:55:48 volumio go-librespot[23884]: time="2026-02-11T22:55:48+07:00" level=debug msg="new websocket client"
Feb 11 22:55:48 volumio go-librespot[23884]: time="2026-02-11T22:55:48+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF"
Feb 11 22:55:48 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 11 22:55:48 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 11 22:55:48 volumio volumio[23462]: info: Connection to go-librespot Websocket established
Feb 11 22:55:48 volumio volumio[23462]: info: Connection to go-librespot Websocket closed
Feb 11 22:55:49 volumio volumio[23462]: info: MYVOLUMIO: Adding device
Feb 11 22:55:49 volumio volumio[23462]: info: MYVOLUMIO: Evaluating Server
Feb 11 22:55:50 volumio volumio[23462]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Feb 11 22:55:50 volumio volumio[23462]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 11 22:55:50 volumio volumio[23462]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled
Feb 11 22:55:50 volumio volumio-remote-updater[643]: Test mode disabled
Feb 11 22:55:50 volumio volumio-remote-updater[643]: Alpha mode disabled
Feb 11 22:55:50 volumio volumio-remote-updater[643]: Alpha legacy test mode disabled
Feb 11 22:55:50 volumio volumio[23462]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled
Feb 11 22:55:51 volumio volumio[23462]: info: Update Ready: {"changeLogLink":"http://volumio.org","description":"FIXES
\n\n- Fix for CPU utilization spike
\n- Fix for triggerhappy input permission
\n
\nNEW ADDITIONS
\n\n- Add BLE onboarding plugin
\n- Enable vc4-kms-v3d for all compatible RPi models
\n- Update Tidal SDK
\n
\n","title":"Update v4.096","updateavailable":true}
Feb 11 22:55:51 volumio volumio[23462]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache
Feb 11 22:55:51 volumio volumio[23462]: info: Getting Spotify volume
Feb 11 22:55:51 volumio volumio[23462]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Feb 11 22:55:51 volumio volumio[23462]: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 11 22:55:51 volumio volumio[23462]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) {
Feb 11 22:55:51 volumio volumio[23462]: errno: -111,
Feb 11 22:55:51 volumio volumio[23462]: code: 'ECONNREFUSED',
Feb 11 22:55:51 volumio volumio[23462]: syscall: 'connect',
Feb 11 22:55:51 volumio volumio[23462]: address: '127.0.0.1',
Feb 11 22:55:51 volumio volumio[23462]: port: 9879,
Feb 11 22:55:51 volumio volumio[23462]: response: undefined
Feb 11 22:55:51 volumio volumio[23462]: }
Feb 11 22:55:51 volumio volumio[23462]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Feb 11 22:55:51 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 26.
Feb 11 22:55:51 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 11 22:55:51 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 11 22:55:51 volumio go-librespot[23924]: go-librespot daemon starting...
Feb 11 22:55:51 volumio go-librespot[23926]: time="2026-02-11T22:55:51+07:00" level=info msg="running go-librespot 0.4.0"
Feb 11 22:55:51 volumio go-librespot[23926]: time="2026-02-11T22:55:51+07:00" level=debug msg="app state loaded"
Feb 11 22:55:51 volumio go-librespot[23926]: time="2026-02-11T22:55:51+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 11 22:55:52 volumio go-librespot[23926]: time="2026-02-11T22:55:52+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 11 22:55:52 volumio go-librespot[23926]: time="2026-02-11T22:55:52+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 22:55:52 volumio go-librespot[23926]: time="2026-02-11T22:55:52+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 22:55:52 volumio go-librespot[23926]: time="2026-02-11T22:55:52+07:00" level=info msg="zeroconf server listening on port 43129"
Feb 11 22:55:52 volumio go-librespot[23926]: time="2026-02-11T22:55:52+07:00" level=debug msg="obtained new client token: AAA2Cvp7+qDZuU4kwqDeesnsbBApqG/MRuNOn8Qgfo+6D6K09RP/jQLKle+a6n8EDKR2chYXtbcMiHYkLfuNV01e341LM9TKkOJYCqxsxNZEW8vyNwqj7oDxZf5sUK15/N7bk4CZErsFG29y5iq5IFtyJht6Oz55MlWvNF6pGnqlqdciTZ/AA36g2XPzfCWq1sXAXYa0hiW1kfrmA/6iBi6OlaYnr8/UrHw3s9XytVFoT8zqOzadLiUjDg=="
Feb 11 22:55:52 volumio go-librespot[23926]: time="2026-02-11T22:55:52+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 22:55:52 volumio go-librespot[23926]: time="2026-02-11T22:55:52+07:00" level=debug msg="connected to ap-gae2.spotify.com:443"
Feb 11 22:55:52 volumio go-librespot[23926]: time="2026-02-11T22:55:52+07:00" level=debug msg="completed keyexchange"
Feb 11 22:55:52 volumio go-librespot[23926]: time="2026-02-11T22:55:52+07:00" level=debug msg="completed challenge"
Feb 11 22:55:52 volumio go-librespot[23926]: time="2026-02-11T22:55:52+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Feb 11 22:55:52 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 11 22:55:52 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 11 22:55:52 volumio sudo[23936]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-11 22:54'
Feb 11 22:55:52 volumio sudo[23936]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 11 22:55:53 volumio sudo[23936]: pam_unix(sudo:session): session closed for user root
Feb 11 22:55:53 volumio volumio-remote-updater[643]: [2026-02-11 22:55:53] [error] handle_read_frame error: websocketpp.transport:7 (End of File)
Feb 11 22:55:53 volumio volumio-remote-updater[643]: [2026-02-11 22:55:53] [disconnect] Disconnect close local:[1006,End of File] remote:[1006]
Feb 11 22:55:53 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE
Feb 11 22:55:53 volumio systemd[1]: volumio.service: Failed with result 'exit-code'.
Feb 11 22:55:53 volumio systemd[1]: volumio.service: Consumed 57.878s CPU time.
Feb 11 22:55:53 volumio systemd[1]: Started dynamicswap.service - dynamicswap service.
Feb 11 22:55:53 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 12339.
Feb 11 22:55:53 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module.
Feb 11 22:55:53 volumio systemd[1]: volumio.service: Consumed 57.878s CPU time.
Feb 11 22:55:53 volumio systemd[1]: Started volumio.service - Volumio Backend Module.
Feb 11 22:55:53 volumio systemd[1]: dynamicswap.service: Deactivated successfully.
Feb 11 22:55:55 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 27.
Feb 11 22:55:55 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 11 22:55:55 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 11 22:55:55 volumio go-librespot[23957]: go-librespot daemon starting...
Feb 11 22:55:55 volumio go-librespot[23958]: time="2026-02-11T22:55:55+07:00" level=info msg="running go-librespot 0.4.0"
Feb 11 22:55:55 volumio go-librespot[23958]: time="2026-02-11T22:55:55+07:00" level=debug msg="app state loaded"
Feb 11 22:55:55 volumio go-librespot[23958]: time="2026-02-11T22:55:55+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 11 22:55:56 volumio go-librespot[23958]: time="2026-02-11T22:55:56+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 22:55:56 volumio go-librespot[23958]: time="2026-02-11T22:55:56+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 22:55:56 volumio go-librespot[23958]: time="2026-02-11T22:55:56+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 22:55:56 volumio go-librespot[23958]: time="2026-02-11T22:55:56+07:00" level=info msg="zeroconf server listening on port 40147"
Feb 11 22:55:56 volumio go-librespot[23958]: time="2026-02-11T22:55:56+07:00" level=debug msg="obtained new client token: AADVJKV8V7+iD9wf+tZiB8zUr+U3BtJ2YHprtFBNbiPQKEBvJwxoDCg4VGrDzrtHBke9/jja52+tZMBCc/pK/wdeG2sJtQDLZceaLBfsai3wXD/uCwkd/HkZxbastSBvM0eDqnBVA2SHv9N7Go0qVHMp2B5dwUy4NNEHgK3MxI2RmhAfv7vEog3Td1nd28O1Dn/dAaA+YQyhUrUGiRNYM9RMhCwfwY2vspNUPOnlPQIAG5SaIIlq4k/qYg=="
Feb 11 22:55:56 volumio go-librespot[23958]: time="2026-02-11T22:55:56+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 11 22:55:56 volumio go-librespot[23958]: time="2026-02-11T22:55:56+07:00" level=debug msg="completed keyexchange"
Feb 11 22:55:56 volumio go-librespot[23958]: time="2026-02-11T22:55:56+07:00" level=debug msg="completed challenge"
Feb 11 22:55:56 volumio go-librespot[23958]: time="2026-02-11T22:55:56+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 22:55:56 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 11 22:55:56 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 11 22:55:57 volumio volumio[23947]: info: -------------------------------------------
Feb 11 22:55:57 volumio volumio[23947]: info: ----- Volumio3 ----
Feb 11 22:55:57 volumio volumio[23947]: info: -------------------------------------------
Feb 11 22:55:57 volumio volumio[23947]: info: ----- System startup ----
Feb 11 22:55:57 volumio volumio[23947]: info: -------------------------------------------
Feb 11 22:55:58 volumio volumio-remote-updater[643]: [2026-02-11 22:55:58] [connect] Successful connection
Feb 11 22:55:58 volumio volumio[23947]: info: MYVOLUMIO Environment detected
Feb 11 22:55:58 volumio volumio[23947]: info: Plugin folders cleanup
Feb 11 22:55:58 volumio volumio[23947]: info: Scanning into folder /volumio/app/plugins/
Feb 11 22:55:58 volumio volumio[23947]: info: Scanning category audio_interface
Feb 11 22:55:58 volumio volumio[23947]: info: Scanning category miscellanea
Feb 11 22:55:58 volumio volumio[23947]: info: Scanning category music_service
Feb 11 22:55:58 volumio volumio[23947]: info: Scanning category plugins.json
Feb 11 22:55:58 volumio volumio[23947]: info: Scanning category system_controller
Feb 11 22:55:58 volumio volumio[23947]: info: Scanning category user_interface
Feb 11 22:55:58 volumio volumio[23947]: info: Scanning into folder /data/plugins/
Feb 11 22:55:58 volumio volumio[23947]: info: Scanning category music_service
Feb 11 22:55:58 volumio volumio[23947]: info: Plugin folders cleanup completed
Feb 11 22:55:58 volumio volumio[23947]: info: -------------------------------------------
Feb 11 22:55:58 volumio volumio[23947]: info: ----- Core plugins startup ----
Feb 11 22:55:58 volumio volumio[23947]: info: -------------------------------------------
Feb 11 22:55:58 volumio volumio[23947]: info: Loading plugins from folder /volumio/app/plugins/
Feb 11 22:55:58 volumio volumio[23947]: info: Adding plugin upnp to MyMusic Plugins
Feb 11 22:55:58 volumio volumio[23947]: info: Adding plugin airplay_emulation to MyMusic Plugins
Feb 11 22:55:58 volumio volumio[23947]: info: Adding plugin upnp_browser to MyMusic Plugins
Feb 11 22:55:58 volumio volumio[23947]: info: Loading plugins from folder /data/plugins/
Feb 11 22:55:58 volumio volumio[23947]: info: Loading plugin "system"...
Feb 11 22:55:58 volumio volumio[23947]: info: Loading plugin "appearance"...
Feb 11 22:56:00 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 28.
Feb 11 22:56:00 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 11 22:56:00 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 11 22:56:00 volumio go-librespot[23979]: go-librespot daemon starting...
Feb 11 22:56:00 volumio go-librespot[23980]: time="2026-02-11T22:56:00+07:00" level=info msg="running go-librespot 0.4.0"
Feb 11 22:56:00 volumio go-librespot[23980]: time="2026-02-11T22:56:00+07:00" level=debug msg="app state loaded"
Feb 11 22:56:00 volumio go-librespot[23980]: time="2026-02-11T22:56:00+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 11 22:56:00 volumio volumio[23947]: info: Loading plugin "network"...
Feb 11 22:56:00 volumio volumio[23947]: info: Refreshing Cached IP Addresses
Feb 11 22:56:00 volumio sudo[23988]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Feb 11 22:56:00 volumio sudo[23988]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 11 22:56:00 volumio sudo[23988]: pam_unix(sudo:session): session closed for user root
Feb 11 22:56:00 volumio volumio[23947]: info: Loading plugin "services"...
Feb 11 22:56:00 volumio go-librespot[23980]: time="2026-02-11T22:56:00+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 11 22:56:00 volumio go-librespot[23980]: time="2026-02-11T22:56:00+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Feb 11 22:56:00 volumio go-librespot[23980]: time="2026-02-11T22:56:00+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Feb 11 22:56:00 volumio volumio[23947]: info: Loading plugin "alsa_controller"...
Feb 11 22:56:00 volumio sudo[23990]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Feb 11 22:56:00 volumio sudo[23990]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 11 22:56:00 volumio sudo[23990]: pam_unix(sudo:session): session closed for user root
Feb 11 22:56:00 volumio go-librespot[23980]: time="2026-02-11T22:56:00+07:00" level=info msg="zeroconf server listening on port 40171"
Feb 11 22:56:00 volumio sudo[23998]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan
Feb 11 22:56:00 volumio sudo[23998]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 11 22:56:00 volumio volumio[23947]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Feb 11 22:56:00 volumio volumio[23947]: info: Loading plugin "wizard"...
Feb 11 22:56:00 volumio volumio[23947]: info: Loading plugin "networkfs"...
Feb 11 22:56:00 volumio volumio[23947]: info: Starting Udev Watcher for removable devices
Feb 11 22:56:01 volumio go-librespot[23980]: time="2026-02-11T22:56:01+07:00" level=debug msg="obtained new client token: AAATMYdvU9aT27C4baMA3NG+rzBgB/Hc+Tj8XmlNuPY7gmJrX2UdQ9E6B3+wvO7VPAYVodKgHb1VgqDiSnu96nSNY/0ud6KMz4wz2AN5TTBqpRj9jIs6uPRJQtb5jqTVxK2rVujksS1D1X9pz57Q5AWFeDQ1IJ4WB3ZIfrXqQ8OcKCUQ1hSeilfEdkNwit7w8/GVQd7CTwyuYQs/by1nA1qq00Q5ZZy+JnjuBTHKjL3zBdW88KmX6517VQ=="
Feb 11 22:56:01 volumio volumio[23947]: info: Ignoring mount for partition: boot
Feb 11 22:56:01 volumio volumio[23947]: info: Ignoring mount for partition: volumio
Feb 11 22:56:01 volumio volumio[23947]: info: Ignoring mount for partition: volumio_data
Feb 11 22:56:01 volumio volumio[23947]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Feb 11 22:56:01 volumio volumio[23947]: info: Loading plugin "volumio_command_line_client"...
Feb 11 22:56:01 volumio volumio[23947]: info: Loading plugin "upnp"...
Feb 11 22:56:01 volumio volumio[23947]: info: [1770825361082] Starting Upmpd Daemon
Feb 11 22:56:01 volumio volumio[23947]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Feb 11 22:56:01 volumio volumio[23947]: info: Loading plugin "my_music"...
Feb 11 22:56:01 volumio volumio[23947]: info: Loading plugin "mpd"...
Feb 11 22:56:01 volumio go-librespot[23980]: time="2026-02-11T22:56:01+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 11 22:56:01 volumio go-librespot[23980]: time="2026-02-11T22:56:01+07:00" level=debug msg="completed keyexchange"
Feb 11 22:56:01 volumio go-librespot[23980]: time="2026-02-11T22:56:01+07:00" level=debug msg="completed challenge"
Feb 11 22:56:01 volumio go-librespot[23980]: time="2026-02-11T22:56:01+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Feb 11 22:56:01 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 11 22:56:01 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 11 22:56:01 volumio volumio[23947]: info: Loading plugin "upnp_browser"...
Feb 11 22:56:03 volumio sudo[23998]: pam_unix(sudo:session): session closed for user root
Feb 11 22:56:04 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 29.
Feb 11 22:56:04 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 11 22:56:04 volumio volumio[23947]: info: Starting UPNP Browser
Feb 11 22:56:04 volumio volumio[23947]: info: Loading plugin "alarm-clock"...
Feb 11 22:56:04 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 11 22:56:04 volumio go-librespot[24021]: go-librespot daemon starting...
Feb 11 22:56:04 volumio go-librespot[24022]: time="2026-02-11T22:56:04+07:00" level=info msg="running go-librespot 0.4.0"
Feb 11 22:56:04 volumio go-librespot[24022]: time="2026-02-11T22:56:04+07:00" level=debug msg="app state loaded"
Feb 11 22:56:04 volumio go-librespot[24022]: time="2026-02-11T22:56:04+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 11 22:56:04 volumio volumio[23947]: info: Loading plugin "airplay_emulation"...
Feb 11 22:56:04 volumio volumio[23947]: info: Starting Shairport Sync
Feb 11 22:56:05 volumio volumio[23947]: info: Loading plugin "last_100"...
Feb 11 22:56:05 volumio volumio[23947]: info: Loading plugin "webradio"...
Feb 11 22:56:05 volumio volumio[23947]: info: Loading plugin "i2s_dacs"...
Feb 11 22:56:05 volumio volumio[23947]: info: Loading plugin "volumiodiscovery"...
Feb 11 22:56:05 volumio volumio[23947]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Feb 11 22:56:05 volumio volumio[23947]: *** WARNING *** Please fix your application to use the native API of Avahi!
Feb 11 22:56:05 volumio volumio[23947]: *** WARNING *** For more information see
Feb 11 22:56:05 volumio volumio[23947]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Feb 11 22:56:05 volumio volumio[23947]: *** WARNING *** Please fix your application to use the native API of Avahi!
Feb 11 22:56:05 volumio volumio[23947]: *** WARNING *** For more information see
Feb 11 22:56:05 volumio node[23947]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Feb 11 22:56:05 volumio go-librespot[24022]: time="2026-02-11T22:56:05+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 22:56:05 volumio go-librespot[24022]: time="2026-02-11T22:56:05+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 22:56:05 volumio go-librespot[24022]: time="2026-02-11T22:56:05+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 22:56:05 volumio node[23947]: *** WARNING *** Please fix your application to use the native API of Avahi!
Feb 11 22:56:05 volumio node[23947]: *** WARNING *** For more information see
Feb 11 22:56:05 volumio node[23947]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Feb 11 22:56:05 volumio node[23947]: *** WARNING *** Please fix your application to use the native API of Avahi!
Feb 11 22:56:05 volumio node[23947]: *** WARNING *** For more information see
Feb 11 22:56:05 volumio volumio[23947]: info: Applying required configuration parameters for plugin volumiodiscovery
Feb 11 22:56:05 volumio volumio[23947]: info: Discovery: Started advertising with name: Volumio
Feb 11 22:56:05 volumio go-librespot[24022]: time="2026-02-11T22:56:05+07:00" level=info msg="zeroconf server listening on port 33569"
Feb 11 22:56:05 volumio volumio[23947]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Feb 11 22:56:05 volumio volumio[23947]: info: Loading plugin "spop"...
Feb 11 22:56:05 volumio go-librespot[24022]: time="2026-02-11T22:56:05+07:00" level=debug msg="obtained new client token: AADqWUBatGlDirR1ybtYPV/VqlwyGGNsFQZUMEIwacCgUV0DvD3A19oJQmj65RaIXWqlbAKhXkq3iUHL4ZHiJVaIDGKGs+gYKkYchB7hF+Xllq1Pketia9Q2JBCwcy5FxfyYyiK0AysvfBbOCx8j1H8lyGmazBhK86Ka1cREv4QXw+T7sm3BH8E1m9V1Fjm/KANlkyXciffgsXr/LvPIX1Mo3ONDtMsRnab1MnWC89TROGsq0zIRzOMLIA=="
Feb 11 22:56:05 volumio go-librespot[24022]: time="2026-02-11T22:56:05+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 11 22:56:05 volumio go-librespot[24022]: time="2026-02-11T22:56:05+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF"
Feb 11 22:56:05 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 11 22:56:05 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 11 22:56:07 volumio volumio[23947]: info: Loading plugin "ytcr"...
Feb 11 22:56:09 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 30.
Feb 11 22:56:09 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 11 22:56:09 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 11 22:56:09 volumio go-librespot[24035]: go-librespot daemon starting...
Feb 11 22:56:09 volumio go-librespot[24036]: time="2026-02-11T22:56:09+07:00" level=info msg="running go-librespot 0.4.0"
Feb 11 22:56:09 volumio go-librespot[24036]: time="2026-02-11T22:56:09+07:00" level=debug msg="app state loaded"
Feb 11 22:56:09 volumio go-librespot[24036]: time="2026-02-11T22:56:09+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 11 22:56:09 volumio go-librespot[24036]: time="2026-02-11T22:56:09+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 11 22:56:09 volumio go-librespot[24036]: time="2026-02-11T22:56:09+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 22:56:09 volumio go-librespot[24036]: time="2026-02-11T22:56:09+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 22:56:09 volumio go-librespot[24036]: time="2026-02-11T22:56:09+07:00" level=info msg="zeroconf server listening on port 35625"
Feb 11 22:56:09 volumio volumio[23947]: info: Loading plugin "ytmusic"...
Feb 11 22:56:09 volumio go-librespot[24036]: time="2026-02-11T22:56:09+07:00" level=debug msg="obtained new client token: AACqc0UvuZ3Pd/hgA8iE9IpjafCJyHG40gX9W91OsaFYhXgxajZRHiTiBgBihe4/ULl8kvqeZggmRJrQJOEeSLPRHLrRVrD7KF2xsZnRuZpCqJqpoEz62/t0sIUKeTXZw6CCrMnjNfCziUf2Miri0TqNCI7tJLzlG538iCLfVv3+AnjFa6dMQa+HxMEdPuSAKh/5k5jjjoS3CEIssW1FbGzRXrc9OlZF2CaoyH2P/4sfd7yJ1DBXVr8Z4A=="
Feb 11 22:56:10 volumio go-librespot[24036]: time="2026-02-11T22:56:10+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 11 22:56:10 volumio go-librespot[24036]: time="2026-02-11T22:56:10+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF"
Feb 11 22:56:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 11 22:56:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 11 22:56:10 volumio volumio[23947]: info: Loading plugin "outputs"...
Feb 11 22:56:10 volumio volumio-remote-updater[643]: [2026-02-11 22:56:10] [connect] Successful connection
Feb 11 22:56:10 volumio volumio[23947]: info: Loading plugin "albumart"...
Feb 11 22:56:10 volumio volumio[23947]: info: Plugin example_plugin is not enabled
Feb 11 22:56:10 volumio volumio[23947]: info: Loading plugin "inputs"...
Feb 11 22:56:10 volumio volumio[23947]: info: Loading plugin "updater_comm"...
Feb 11 22:56:11 volumio volumio[23947]: info: Plugin mpdemulation is not enabled
Feb 11 22:56:11 volumio volumio[23947]: info: Loading plugin "rest_api"...
Feb 11 22:56:11 volumio volumio[23947]: info: Loading plugin "websocket"...
Feb 11 22:56:11 volumio volumio[23947]: info: Starting Socket.io Server version 1.7.4
Feb 11 22:56:11 volumio volumio[23947]: info: Loading plugin "RoonBridge"...
Feb 11 22:56:11 volumio volumio[23947]: info: Applying required configuration parameters for plugin RoonBridge
Feb 11 22:56:11 volumio volumio[23947]: info: Loading i18n strings for locale en
Feb 11 22:56:11 volumio volumio[23947]: Updating browse sources language
Feb 11 22:56:11 volumio volumio[23947]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 11 22:56:12 volumio volumio[23947]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Feb 11 22:56:12 volumio volumio[23947]: info: CoreCommandRouter::initPlayerControls
Feb 11 22:56:12 volumio volumio[23947]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 22:56:12 volumio volumio[23947]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 22:56:12 volumio volumio[23947]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 22:56:12 volumio volumio[23947]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 22:56:12 volumio volumio[23947]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 22:56:12 volumio volumio[23947]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 22:56:12 volumio volumio[23947]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 22:56:12 volumio volumio[23947]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 22:56:12 volumio volumio[23947]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Feb 11 22:56:12 volumio volumio[23947]: Express server listening on port 3000
Feb 11 22:56:12 volumio volumio[23947]: [Metrics] WebUI: 15s 876.31ms
Feb 11 22:56:12 volumio volumio[24057]: Forking 3 albumart workers
Feb 11 22:56:12 volumio volumio[23947]: info: CoreStateMachine::resetVolumioState
Feb 11 22:56:12 volumio volumio[23947]: info: CoreStateMachine::getcurrentVolume
Feb 11 22:56:12 volumio volumio[23947]: info: CoreCommandRouter::volumioRetrievevolume
Feb 11 22:56:12 volumio sudo[24091]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Feb 11 22:56:12 volumio sudo[24091]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 11 22:56:12 volumio sudo[24100]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Feb 11 22:56:12 volumio sudo[24091]: pam_unix(sudo:session): session closed for user root
Feb 11 22:56:12 volumio sudo[24100]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 11 22:56:12 volumio volumio[23947]: info: Volumio Network Manager: Network status updated: 1
Feb 11 22:56:12 volumio sudo[24100]: pam_unix(sudo:session): session closed for user root
Feb 11 22:56:12 volumio volumio[23947]: info: VolumeController:: Volume=100 Mute =false
Feb 11 22:56:12 volumio volumio[23947]: info: CoreStateMachine::pushState
Feb 11 22:56:12 volumio volumio[23947]: info: CorePlayQueue::getTrack 0
Feb 11 22:56:12 volumio volumio[23947]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Feb 11 22:56:12 volumio volumio[23947]: info: CoreCommandRouter::volumioPushState
Feb 11 22:56:12 volumio volumio[23947]: info: CoreStateMachine::updateTrackBlock
Feb 11 22:56:12 volumio volumio[23947]: info: CorePlayQueue::getTrackBlock
Feb 11 22:56:12 volumio volumio[23947]: info: CoreCommandRouter::volumioRetrievevolume
Feb 11 22:56:12 volumio volumio-remote-updater[643]: [2026-02-11 22:56:12] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770825370 101
Feb 11 22:56:12 volumio volumio[23947]: 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 22:56:12 volumio volumio[23947]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 11 22:56:12 volumio volumio[23947]: info: Reloading queue from file
Feb 11 22:56:12 volumio volumio[23947]: info: CoreStateMachine::setRepeat null single undefined
Feb 11 22:56:12 volumio volumio[23947]: info: CoreStateMachine::pushState
Feb 11 22:56:12 volumio volumio[23947]: info: CorePlayQueue::getTrack 0
Feb 11 22:56:12 volumio volumio[23947]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Feb 11 22:56:12 volumio volumio[23947]: info: CoreCommandRouter::volumioPushState
Feb 11 22:56:12 volumio volumio[23947]: info: CoreStateMachine::setRandom null
Feb 11 22:56:12 volumio volumio[23947]: info: CoreStateMachine::pushState
Feb 11 22:56:12 volumio volumio[23947]: info: CorePlayQueue::getTrack 0
Feb 11 22:56:12 volumio volumio[23947]: info: CoreCommandRouter::volumioPushState
Feb 11 22:56:12 volumio volumio[23947]: info: Setting Device type: Raspberry PI
Feb 11 22:56:13 volumio volumio[23947]: info: Completed loading Core Plugins
Feb 11 22:56:13 volumio volumio[23947]: info: Preparing to generate the ALSA configuration file
Feb 11 22:56:13 volumio volumio[23947]: info: VolumeController:: Volume=100 Mute =false
Feb 11 22:56:13 volumio volumio[23947]: info: CoreStateMachine::pushState
Feb 11 22:56:13 volumio volumio[23947]: info: CorePlayQueue::getTrack 0
Feb 11 22:56:13 volumio volumio[23947]: info: CoreCommandRouter::volumioPushState
Feb 11 22:56:13 volumio volumio[23947]: info: Asound.conf file unchanged, so no further update is needed
Feb 11 22:56:13 volumio volumio[23947]: info: Output device has changed, restarting MPD
Feb 11 22:56:13 volumio volumio[23947]: info: Output device has changed, restarting Shairport Sync
Feb 11 22:56:13 volumio volumio[23947]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 22:56:13 volumio volumio[23947]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 11 22:56:13 volumio sudo[24118]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service
Feb 11 22:56:13 volumio sudo[24118]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 11 22:56:13 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 31.
Feb 11 22:56:13 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 11 22:56:13 volumio sudo[24122]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Feb 11 22:56:13 volumio sudo[24122]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 11 22:56:13 volumio sudo[24120]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Feb 11 22:56:13 volumio sudo[24120]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 11 22:56:13 volumio sudo[24120]: pam_unix(sudo:session): session closed for user root
Feb 11 22:56:13 volumio volumio[23947]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Feb 11 22:56:13 volumio volumio[23947]: info: ___________ START PLUGINS ___________
Feb 11 22:56:13 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 11 22:56:13 volumio go-librespot[24128]: go-librespot daemon starting...
Feb 11 22:56:13 volumio volumio[23947]: info: ControllerMpd::onStart: Initializing MPD
Feb 11 22:56:13 volumio volumio[23947]: info: Creating MPD Configuration file
Feb 11 22:56:13 volumio go-librespot[24131]: time="2026-02-11T22:56:13+07:00" level=info msg="running go-librespot 0.4.0"
Feb 11 22:56:13 volumio go-librespot[24131]: time="2026-02-11T22:56:13+07:00" level=debug msg="app state loaded"
Feb 11 22:56:13 volumio go-librespot[24131]: time="2026-02-11T22:56:13+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 11 22:56:13 volumio volumio[23947]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Feb 11 22:56:13 volumio volumio[23947]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 11 22:56:13 volumio volumio[23947]: info: [1770825373510] CoreMusicLibrary::Adding element Media Servers
Feb 11 22:56:13 volumio volumio[23947]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 11 22:56:13 volumio systemd[1]: Stopping mpd.service - Music Player Daemon...
Feb 11 22:56:13 volumio sudo[24118]: pam_unix(sudo:session): session closed for user root
Feb 11 22:56:13 volumio volumio[23947]: info: UPNP Browser: Client initialized successfully
Feb 11 22:56:13 volumio sudo[24141]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Feb 11 22:56:13 volumio sudo[24138]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Feb 11 22:56:13 volumio sudo[24138]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 11 22:56:13 volumio sudo[24141]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 11 22:56:13 volumio systemd[1]: mpd.service: Deactivated successfully.
Feb 11 22:56:13 volumio systemd[1]: Stopped mpd.service - Music Player Daemon.
Feb 11 22:56:13 volumio systemd[1]: mpd.service: Consumed 7.157s CPU time.
Feb 11 22:56:13 volumio sudo[24138]: pam_unix(sudo:session): session closed for user root
Feb 11 22:56:13 volumio systemd[1]: mpd.socket: Deactivated successfully.
Feb 11 22:56:13 volumio volumio[23947]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 22:56:13 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket.
Feb 11 22:56:13 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket...
Feb 11 22:56:13 volumio volumio[23947]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 11 22:56:13 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket.
Feb 11 22:56:13 volumio systemd[1]: Starting mpd.service - Music Player Daemon...
Feb 11 22:56:13 volumio systemd[1]: mpd.service: Deactivated successfully.
Feb 11 22:56:13 volumio systemd[1]: Stopped mpd.service - Music Player Daemon.
Feb 11 22:56:13 volumio systemd[1]: mpd.socket: Deactivated successfully.
Feb 11 22:56:13 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket.
Feb 11 22:56:13 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket...
Feb 11 22:56:13 volumio volumio[23947]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Feb 11 22:56:13 volumio volumio[23947]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 22:56:13 volumio volumio[23947]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 11 22:56:14 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket.
Feb 11 22:56:14 volumio systemd[1]: Starting mpd.service - Music Player Daemon...
Feb 11 22:56:14 volumio volumio[23947]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Feb 11 22:56:14 volumio volumio[23947]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 11 22:56:14 volumio volumio[23947]: info: [1770825374092] CoreMusicLibrary::Adding element Last_100
Feb 11 22:56:14 volumio volumio[23947]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 11 22:56:14 volumio volumio[23947]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 11 22:56:14 volumio volumio[23947]: info: [1770825374115] CoreMusicLibrary::Adding element Webradio
Feb 11 22:56:14 volumio volumio[23947]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 11 22:56:14 volumio volumio[23947]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Feb 11 22:56:14 volumio volumio[23947]: info: Initializing BBC Radios
Feb 11 22:56:14 volumio go-librespot[24131]: time="2026-02-11T22:56:14+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 22:56:14 volumio go-librespot[24131]: time="2026-02-11T22:56:14+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 22:56:14 volumio go-librespot[24131]: time="2026-02-11T22:56:14+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 22:56:14 volumio go-librespot[24131]: time="2026-02-11T22:56:14+07:00" level=info msg="zeroconf server listening on port 40915"
Feb 11 22:56:14 volumio volumio[23947]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Feb 11 22:56:14 volumio volumio[23947]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 11 22:56:14 volumio volumio[23947]: info: Creating Spotify config file
Feb 11 22:56:14 volumio volumio[23947]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 22:56:14 volumio go-librespot[24131]: time="2026-02-11T22:56:14+07:00" level=debug msg="obtained new client token: AAAAoVEbQd6MN2JSW2HrAToVN9fxpKGtuzGxE44TI+jDFTqGbjxFAZdp75sQvsUsdWHtFlBHSclBVn/UjHox/V7Jl8ezZVb0sYRZX1Gly+RymUGzZ0+XZYcWu1XfMH6ROPtJnMtcXfVUUw2LD1ZNYx4tGnH7gmMZH+HUaNsg9lFXb0oRS74IjtaoVrdTnXckrmWYlKYXRKYrXEQMINRUVy4xzDGGRAMaVjZrha70/issWYQgG9wAvaL9bQ=="
Feb 11 22:56:14 volumio sudo[24156]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log
Feb 11 22:56:14 volumio sudo[24156]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0)
Feb 11 22:56:14 volumio sudo[24156]: pam_unix(sudo:session): session closed for user root
Feb 11 22:56:14 volumio go-librespot[24131]: time="2026-02-11T22:56:14+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 11 22:56:14 volumio go-librespot[24131]: time="2026-02-11T22:56:14+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF"
Feb 11 22:56:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 11 22:56:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 11 22:56:15 volumio volumio[24072]: Starting albumart workers
Feb 11 22:56:15 volumio volumio[23947]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 11 22:56:15 volumio volumio[23947]: info: [1770825375669] CoreMusicLibrary::Adding element YouTube Music
Feb 11 22:56:15 volumio volumio[24070]: Starting albumart workers
Feb 11 22:56:15 volumio volumio[23947]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 11 22:56:15 volumio volumio[23947]: Cannot find translation for source YouTube Music
Feb 11 22:56:15 volumio volumio[24071]: Starting albumart workers
Feb 11 22:56:15 volumio volumio[23947]: info: Volumio Calling Home
Feb 11 22:56:15 volumio sudo[24173]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service
Feb 11 22:56:15 volumio sudo[24173]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 11 22:56:16 volumio sudo[24173]: pam_unix(sudo:session): session closed for user root
Feb 11 22:56:16 volumio volumio[23947]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7
Feb 11 22:56:16 volumio volumio[23947]: info: Discovery: Found device Volumio
Feb 11 22:56:16 volumio volumio[23947]: info: CoreCommandRouter::volumioGetState
Feb 11 22:56:16 volumio volumio[23947]: info: CorePlayQueue::getTrack 0
Feb 11 22:56:16 volumio volumio[23947]: info: MPD Permissions set
Feb 11 22:56:16 volumio volumio[23947]: info: MPD Permissions set
Feb 11 22:56:16 volumio volumio[23947]: info: Upmpdcli Daemon Started
Feb 11 22:56:16 volumio volumio[23947]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7
Feb 11 22:56:16 volumio volumio[23947]: info: Discovery: Found device Volumio
Feb 11 22:56:16 volumio volumio[23947]: info: CoreCommandRouter::volumioGetState
Feb 11 22:56:16 volumio volumio[23947]: info: CorePlayQueue::getTrack 0
Feb 11 22:56:16 volumio volumio[23947]: info: Volumio called home
Feb 11 22:56:16 volumio volumio[23947]: info: Spotify config file written
Feb 11 22:56:16 volumio volumio[23947]: 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 22:56:17 volumio volumio[23947]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 22:56:17 volumio volumio[23947]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 22:56:17 volumio volumio[23947]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 22:56:17 volumio volumio[23947]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 22:56:17 volumio volumio[23947]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 22:56:17 volumio volumio[23947]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 22:56:17 volumio volumio[23947]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 22:56:17 volumio volumio[23947]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 22:56:17 volumio sudo[24179]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service
Feb 11 22:56:17 volumio sudo[24179]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 11 22:56:17 volumio volumio[23947]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 11 22:56:17 volumio volumio[23947]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 22:56:17 volumio volumio[23947]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 22:56:17 volumio volumio[23947]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 22:56:17 volumio volumio[23947]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 22:56:17 volumio volumio[23947]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 22:56:17 volumio volumio[23947]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 22:56:17 volumio volumio[23947]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 22:56:17 volumio volumio[23947]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 22:56:17 volumio volumio[23947]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 22:56:17 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 11 22:56:17 volumio volumio[23947]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 11 22:56:17 volumio volumio[23947]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Feb 11 22:56:17 volumio volumio[23947]: info: No need to fix Spotify hosts
Feb 11 22:56:17 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 11 22:56:17 volumio go-librespot[24191]: go-librespot daemon starting...
Feb 11 22:56:17 volumio sudo[24179]: pam_unix(sudo:session): session closed for user root
Feb 11 22:56:17 volumio go-librespot[24192]: time="2026-02-11T22:56:17+07:00" level=info msg="running go-librespot 0.4.0"
Feb 11 22:56:17 volumio go-librespot[24192]: time="2026-02-11T22:56:17+07:00" level=debug msg="app state loaded"
Feb 11 22:56:17 volumio go-librespot[24192]: time="2026-02-11T22:56:17+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 11 22:56:18 volumio go-librespot[24192]: time="2026-02-11T22:56:18+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 11 22:56:18 volumio go-librespot[24192]: time="2026-02-11T22:56:18+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]"
Feb 11 22:56:18 volumio go-librespot[24192]: time="2026-02-11T22:56:18+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]"
Feb 11 22:56:18 volumio go-librespot[24192]: time="2026-02-11T22:56:18+07:00" level=info msg="zeroconf server listening on port 38195"
Feb 11 22:56:18 volumio go-librespot[24192]: time="2026-02-11T22:56:18+07:00" level=debug msg="obtained new client token: AADqUI+n4jMPe+HfPpAc4juYDGvKu1BsHfpdElJt3CCcB8lLotWf51kA4zUpA7Rde432agVF3sItj5JLSFzFAsurzpGL4b9AZU0r5fou4zT2CYQowtK90J6XHybO6qOg26Gk2y6YBnKgV3w63VgrPEYY7uhfLeo/VevhjiH2znb/zaIxfU1EU9QfB+7Xnydw0exH5w1RLvSk0ljVnkAeAhpKFJKrao/ssXBFNyenQYFNWrVM/jbEy9U="
Feb 11 22:56:18 volumio volumio[23947]: info: Starting Shairport Sync
Feb 11 22:56:18 volumio volumio[23947]: info: Starting Shairport Sync
Feb 11 22:56:18 volumio volumio[23947]: info: Starting Shairport Sync
Feb 11 22:56:18 volumio sudo[24219]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Feb 11 22:56:18 volumio sudo[24219]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 11 22:56:18 volumio go-librespot[24192]: time="2026-02-11T22:56:18+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 11 22:56:18 volumio sudo[24221]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Feb 11 22:56:18 volumio sudo[24221]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 11 22:56:18 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver...
Feb 11 22:56:18 volumio systemd[1]: shairport-sync.service: Deactivated successfully.
Feb 11 22:56:18 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Feb 11 22:56:18 volumio systemd[1]: shairport-sync.service: Consumed 2.363s CPU time.
Feb 11 22:56:18 volumio go-librespot[24192]: time="2026-02-11T22:56:18+07:00" level=debug msg="completed keyexchange"
Feb 11 22:56:18 volumio go-librespot[24192]: time="2026-02-11T22:56:18+07:00" level=debug msg="completed challenge"
Feb 11 22:56:18 volumio sudo[24224]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Feb 11 22:56:18 volumio sudo[24224]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 11 22:56:18 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Feb 11 22:56:18 volumio go-librespot[24192]: time="2026-02-11T22:56:18+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials "
Feb 11 22:56:18 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 11 22:56:18 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 11 22:56:18 volumio sudo[24219]: pam_unix(sudo:session): session closed for user root
Feb 11 22:56:18 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver...
Feb 11 22:56:18 volumio systemd[1]: shairport-sync.service: Deactivated successfully.
Feb 11 22:56:18 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Feb 11 22:56:18 volumio volumio[23947]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------
Feb 11 22:56:18 volumio volumio[23947]: SPOTIFY: BQB8RPhpS702RNDQXXbexz1tCaMIWa-Bk1dWb7RWh-NqXebK5GzMsWaTM3Zl-Jc4AxMJJzoQXl382vdQ03arQbucDofePUqwfQzNbYNtBH_0eFBrIub4j9LsGNGmukkaEkCcMpf3wSJRruKZExUNrX97XdxDoSnqRt9TZ9U13VXmOfUtVCXxhh8Vn1MmeArZpx0U_9tOeDPI7YHFGI3tPeuHdVbCHvDq6a4TOCxC8ST4PK-KVMnk0E85wu07jDT5b8nIxFqpXckb9lIO46q2X6K9L99OPPfhbjPlzkAfowDGrFaTv68KGKCq
Feb 11 22:56:18 volumio volumio[23947]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------
Feb 11 22:56:18 volumio volumio[23947]: info: New Spotify access token = BQB8RPhpS702RNDQXXbexz1tCaMIWa-Bk1dWb7RWh-NqXebK5GzMsWaTM3Zl-Jc4AxMJJzoQXl382vdQ03arQbucDofePUqwfQzNbYNtBH_0eFBrIub4j9LsGNGmukkaEkCcMpf3wSJRruKZExUNrX97XdxDoSnqRt9TZ9U13VXmOfUtVCXxhh8Vn1MmeArZpx0U_9tOeDPI7YHFGI3tPeuHdVbCHvDq6a4TOCxC8ST4PK-KVMnk0E85wu07jDT5b8nIxFqpXckb9lIO46q2X6K9L99OPPfhbjPlzkAfowDGrFaTv68KGKCq
Feb 11 22:56:18 volumio volumio[23947]: info: Spotify credentials grant success - running version from March 24, 2019
Feb 11 22:56:18 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver.
Feb 11 22:56:18 volumio sudo[24224]: pam_unix(sudo:session): session closed for user root
Feb 11 22:56:18 volumio sudo[24221]: pam_unix(sudo:session): session closed for user root
Feb 11 22:56:19 volumio volumio[23947]: info: Shairport-Sync Started
Feb 11 22:56:19 volumio volumio[23947]: Error adding Membership: Error: addMembership EINVAL
Feb 11 22:56:19 volumio volumio[23947]: info: Shairport-Sync Started
Feb 11 22:56:19 volumio volumio[23947]: info: Shairport-Sync Started
Feb 11 22:56:19 volumio volumio[23947]: info: CoreCommandRouter::volumioGetState
Feb 11 22:56:19 volumio volumio[23947]: info: CorePlayQueue::getTrack 0
Feb 11 22:56:19 volumio volumio[23947]: 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 22:56:19 volumio volumio[23947]: info: Spotify Successfully logged in
Feb 11 22:56:19 volumio volumio[23947]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Feb 11 22:56:19 volumio volumio[23947]: info: [1770825379482] CoreMusicLibrary::Adding element Spotify
Feb 11 22:56:19 volumio volumio[23947]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Feb 11 22:56:19 volumio volumio[23947]: Cannot find translation for source YouTube Music
Feb 11 22:56:19 volumio volumio[23947]: Cannot find translation for source Spotify
Feb 11 22:56:20 volumio volumio[23947]: info: [yt-cast-receiver] DIAL server listening on port 8098
Feb 11 22:56:20 volumio volumio[23947]: info: CoreCommandRouter::volumioRetrievevolume
Feb 11 22:56:20 volumio volumio[23947]: info: VolumeController:: Volume=100 Mute =false
Feb 11 22:56:20 volumio volumio[23947]: info: CoreCommandRouter::volumioGetState
Feb 11 22:56:20 volumio volumio[23947]: info: CorePlayQueue::getTrack 0
Feb 11 22:56:20 volumio volumio[23947]: info: CoreStateMachine::pushState
Feb 11 22:56:20 volumio volumio[23947]: info: CorePlayQueue::getTrack 0
Feb 11 22:56:20 volumio volumio[23947]: info: CoreCommandRouter::volumioPushState
Feb 11 22:56:21 volumio volumio[23947]: info: go-librespot daemon successfully initialized
Feb 11 22:56:21 volumio mpd[24171]: 2026-02-11T22:56:21 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg
Feb 11 22:56:21 volumio systemd[1]: Started mpd.service - Music Player Daemon.
Feb 11 22:56:21 volumio sudo[24122]: pam_unix(sudo:session): session closed for user root
Feb 11 22:56:21 volumio sudo[24141]: pam_unix(sudo:session): session closed for user root
Feb 11 22:56:21 volumio volumio[23947]: error: MPD error: The expression evaluated to a falsy value:
Feb 11 22:56:21 volumio volumio[23947]: assert.ok(self.idling)
Feb 11 22:56:21 volumio volumio[23947]: error: The expression evaluated to a falsy value:
Feb 11 22:56:21 volumio volumio[23947]: assert.ok(self.idling)
Feb 11 22:56:21 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 32.
Feb 11 22:56:21 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 11 22:56:21 volumio volumio[23947]: info: MPD running with PID24171
Feb 11 22:56:21 volumio volumio[23947]: ,establishing connection
Feb 11 22:56:21 volumio volumio[23947]: error: updateQueue error: null
Feb 11 22:56:21 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 11 22:56:21 volumio go-librespot[24266]: go-librespot daemon starting...
Feb 11 22:56:21 volumio volumio[23947]: info: Completed starting Core Plugins
Feb 11 22:56:21 volumio volumio[23947]: info: -------------------------------------------
Feb 11 22:56:21 volumio volumio[23947]: info: ----- MyVolumio plugins startup ----
Feb 11 22:56:21 volumio volumio[23947]: info: -------------------------------------------
Feb 11 22:56:21 volumio volumio[23947]: info: [MyVolumio PluginManager] Fetching plans data....
Feb 11 22:56:21 volumio go-librespot[24267]: time="2026-02-11T22:56:21+07:00" level=info msg="running go-librespot 0.4.0"
Feb 11 22:56:21 volumio go-librespot[24267]: time="2026-02-11T22:56:21+07:00" level=debug msg="app state loaded"
Feb 11 22:56:21 volumio volumio[23947]: error: updateQueue error: null
Feb 11 22:56:21 volumio go-librespot[24267]: time="2026-02-11T22:56:21+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 11 22:56:22 volumio go-librespot[24267]: time="2026-02-11T22:56:22+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]"
Feb 11 22:56:22 volumio go-librespot[24267]: time="2026-02-11T22:56:22+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 22:56:22 volumio go-librespot[24267]: time="2026-02-11T22:56:22+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 22:56:22 volumio go-librespot[24267]: time="2026-02-11T22:56:22+07:00" level=info msg="zeroconf server listening on port 41299"
Feb 11 22:56:22 volumio go-librespot[24267]: time="2026-02-11T22:56:22+07:00" level=debug msg="obtained new client token: AAAintO920PLdHEcbKxHJxUe2z/KREdXTvnAiGSdLBvkfLGi8B9FjTmTK923vtxmnuw450JFYMGG+1xYBmPShAS7nYtWOgqhDNPiLUjwrN8pDwpP7PQ3izkJGibKMVhVefb0EtoDaC2lhgFhG2YE3YivSkSip7wor/d0ZqjdESwIQ4zy7la71W0IwPH8dZ3zO1clnlGDZicAROnIQ8l8r1jfjGp0e2MwbvNRoTsGzflmntbGEZ5is/gS4Q=="
Feb 11 22:56:22 volumio go-librespot[24267]: time="2026-02-11T22:56:22+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 11 22:56:22 volumio go-librespot[24267]: time="2026-02-11T22:56:22+07:00" level=debug msg="completed keyexchange"
Feb 11 22:56:22 volumio go-librespot[24267]: time="2026-02-11T22:56:22+07:00" level=debug msg="completed challenge"
Feb 11 22:56:22 volumio go-librespot[24267]: time="2026-02-11T22:56:22+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 22:56:22 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 11 22:56:22 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 11 22:56:24 volumio volumio[23947]: info: Initializing connection to go-librespot Websocket
Feb 11 22:56:24 volumio volumio[23947]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 11 22:56:26 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 33.
Feb 11 22:56:26 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 11 22:56:26 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 11 22:56:26 volumio go-librespot[24274]: go-librespot daemon starting...
Feb 11 22:56:26 volumio go-librespot[24275]: time="2026-02-11T22:56:26+07:00" level=info msg="running go-librespot 0.4.0"
Feb 11 22:56:26 volumio go-librespot[24275]: time="2026-02-11T22:56:26+07:00" level=debug msg="app state loaded"
Feb 11 22:56:26 volumio go-librespot[24275]: time="2026-02-11T22:56:26+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 11 22:56:26 volumio go-librespot[24275]: time="2026-02-11T22:56:26+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 22:56:26 volumio go-librespot[24275]: time="2026-02-11T22:56:26+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 22:56:26 volumio go-librespot[24275]: time="2026-02-11T22:56:26+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 22:56:26 volumio go-librespot[24275]: time="2026-02-11T22:56:26+07:00" level=info msg="zeroconf server listening on port 33457"
Feb 11 22:56:26 volumio volumio[23947]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory
Feb 11 22:56:26 volumio go-librespot[24275]: time="2026-02-11T22:56:26+07:00" level=debug msg="obtained new client token: AABBI1itkbgHpTOWjtZS9xdIk1jL2YWEBH76AnMMdxOv8rak8YafuJV+KU5rb7z6hrkiyQEHcVgCKpp8EaX8Oncfkwf7GmA93dlZsbKYJDRZfNjTp3255oC79WtlLtvdhF+ZgTH9f3DBZSSND4KMvGUxhZLYwttmGZHbxb60QkGXmUQIUmO00SjI2maLZJEN4QGeVTuvWD300FVFqQypAGu7tJ1b8V+igKXTNDZbZF12OiqQicjHTncZmQ=="
Feb 11 22:56:26 volumio go-librespot[24275]: time="2026-02-11T22:56:26+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 11 22:56:26 volumio go-librespot[24275]: time="2026-02-11T22:56:26+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF"
Feb 11 22:56:26 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 11 22:56:26 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 11 22:56:27 volumio volumio[23947]: info: Initializing connection to go-librespot Websocket
Feb 11 22:56:27 volumio volumio[23947]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879
Feb 11 22:56:30 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 34.
Feb 11 22:56:30 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 11 22:56:30 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 11 22:56:30 volumio go-librespot[24282]: go-librespot daemon starting...
Feb 11 22:56:30 volumio go-librespot[24283]: time="2026-02-11T22:56:30+07:00" level=info msg="running go-librespot 0.4.0"
Feb 11 22:56:30 volumio go-librespot[24283]: time="2026-02-11T22:56:30+07:00" level=debug msg="app state loaded"
Feb 11 22:56:30 volumio go-librespot[24283]: time="2026-02-11T22:56:30+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 11 22:56:30 volumio volumio[23947]: info: Initializing connection to go-librespot Websocket
Feb 11 22:56:30 volumio go-librespot[24283]: time="2026-02-11T22:56:30+07:00" level=debug msg="new websocket client"
Feb 11 22:56:30 volumio volumio[23947]: info: Connection to go-librespot Websocket established
Feb 11 22:56:30 volumio volumio[23947]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium
Feb 11 22:56:30 volumio volumio[23947]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium
Feb 11 22:56:30 volumio volumio[23947]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium
Feb 11 22:56:30 volumio volumio[23947]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium
Feb 11 22:56:30 volumio volumio[23947]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium
Feb 11 22:56:30 volumio volumio[23947]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium
Feb 11 22:56:30 volumio volumio[23947]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium
Feb 11 22:56:30 volumio volumio[23947]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium
Feb 11 22:56:30 volumio volumio[23947]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium
Feb 11 22:56:30 volumio volumio[23947]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium
Feb 11 22:56:30 volumio volumio[23947]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium
Feb 11 22:56:30 volumio volumio[23947]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar
Feb 11 22:56:30 volumio volumio[23947]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar
Feb 11 22:56:30 volumio volumio[23947]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar
Feb 11 22:56:30 volumio volumio[23947]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar
Feb 11 22:56:30 volumio volumio[23947]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar
Feb 11 22:56:30 volumio volumio[23947]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar
Feb 11 22:56:30 volumio volumio[23947]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar
Feb 11 22:56:30 volumio volumio[23947]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar
Feb 11 22:56:30 volumio volumio[23947]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar
Feb 11 22:56:30 volumio volumio[23947]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar
Feb 11 22:56:30 volumio volumio[23947]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar
Feb 11 22:56:30 volumio volumio[23947]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso
Feb 11 22:56:30 volumio volumio[23947]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso
Feb 11 22:56:30 volumio volumio[23947]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso
Feb 11 22:56:30 volumio volumio[23947]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso
Feb 11 22:56:30 volumio volumio[23947]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso
Feb 11 22:56:30 volumio volumio[23947]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso
Feb 11 22:56:30 volumio volumio[23947]: info: Adding plugin bluetooth to MyMusic Plugins
Feb 11 22:56:30 volumio volumio[23947]: info: Adding plugin multiroom to MyMusic Plugins
Feb 11 22:56:30 volumio volumio[23947]: info: Adding plugin metavolumio to MyMusic Plugins
Feb 11 22:56:30 volumio volumio[23947]: info: Adding plugin cd_controller to MyMusic Plugins
Feb 11 22:56:30 volumio volumio[23947]: info: Adding plugin qobuzconnect to MyMusic Plugins
Feb 11 22:56:30 volumio volumio[23947]: info: Adding plugin smart_inputs to MyMusic Plugins
Feb 11 22:56:30 volumio volumio[23947]: info: Adding plugin tidalconnect to MyMusic Plugins
Feb 11 22:56:30 volumio volumio[23947]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"...
Feb 11 22:56:30 volumio go-librespot[24283]: time="2026-02-11T22:56:30+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 22:56:30 volumio go-librespot[24283]: time="2026-02-11T22:56:30+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 22:56:30 volumio go-librespot[24283]: time="2026-02-11T22:56:30+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 22:56:30 volumio go-librespot[24283]: time="2026-02-11T22:56:30+07:00" level=info msg="zeroconf server listening on port 38929"
Feb 11 22:56:30 volumio go-librespot[24283]: time="2026-02-11T22:56:30+07:00" level=debug msg="obtained new client token: AAB8C7VwPvT+ylukdoJoODNK7KL7U1XWtnsiuots8BzFDgT+GkFXG+jlSKO9ZtefuuqkvifRVcuhAHKUSkOGQSRimuSCir7kVjqpPiVGe66WAz7cgfXgaY9gmIFqdMd+hRnFeQz5+8BtFF5VLaNJ8aEYpuAmG2I/l1q1OrAAIVSTJrZd/F7555wo4rLIT5bdS/R9WPD6/S9MGZEQTWI0pAihoijn/vr7dWXrydWOs/4cGz90uKIkY8LOtA=="
Feb 11 22:56:31 volumio go-librespot[24283]: time="2026-02-11T22:56:31+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 22:56:31 volumio go-librespot[24283]: time="2026-02-11T22:56:31+07:00" level=debug msg="connected to ap-gae2.spotify.com:443"
Feb 11 22:56:31 volumio go-librespot[24283]: time="2026-02-11T22:56:31+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF"
Feb 11 22:56:31 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 11 22:56:31 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 11 22:56:32 volumio volumio[23947]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded
Feb 11 22:56:32 volumio volumio[23947]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio
Feb 11 22:56:32 volumio volumio[23947]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 11 22:56:32 volumio volumio[23947]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Feb 11 22:56:32 volumio volumio[23947]: info: Starting MyVolumio Remote Streaming Endpoints
Feb 11 22:56:32 volumio volumio[23947]: info: MyVolumio login type: Token
Feb 11 22:56:32 volumio volumio[23947]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started
Feb 11 22:56:32 volumio volumio[23947]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"...
Feb 11 22:56:34 volumio volumio[23947]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded
Feb 11 22:56:34 volumio volumio[23947]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services
Feb 11 22:56:34 volumio volumio[23947]: info: Streaming services startup
Feb 11 22:56:34 volumio volumio[23947]: info: Starting Streaming Daemon
Feb 11 22:56:34 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 35.
Feb 11 22:56:34 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon.
Feb 11 22:56:34 volumio sudo[24307]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service
Feb 11 22:56:34 volumio sudo[24307]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Feb 11 22:56:34 volumio volumio[23947]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started
Feb 11 22:56:34 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon.
Feb 11 22:56:34 volumio go-librespot[24310]: go-librespot daemon starting...
Feb 11 22:56:34 volumio sudo[24307]: pam_unix(sudo:session): session closed for user root
Feb 11 22:56:34 volumio go-librespot[24314]: time="2026-02-11T22:56:34+07:00" level=info msg="running go-librespot 0.4.0"
Feb 11 22:56:34 volumio go-librespot[24314]: time="2026-02-11T22:56:34+07:00" level=debug msg="app state loaded"
Feb 11 22:56:34 volumio go-librespot[24314]: time="2026-02-11T22:56:34+07:00" level=info msg="api server listening on 127.0.0.1:9879"
Feb 11 22:56:34 volumio volumio[23947]: info: Getting Spotify volume
Feb 11 22:56:34 volumio volumio[23947]: info: Connection to go-librespot Websocket closed
Feb 11 22:56:34 volumio volumio[23947]: error: Cannot start Volumio Streaming Daemon
Feb 11 22:56:34 volumio volumio[23947]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service
Feb 11 22:56:34 volumio volumio[23947]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found.
Feb 11 22:56:34 volumio volumio[23947]: 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 22:56:34 volumio volumio[23947]: info: CoreCommandRouter::volumioGetState
Feb 11 22:56:34 volumio volumio[23947]: info: CorePlayQueue::getTrack 0
Feb 11 22:56:34 volumio volumio[23947]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100
Feb 11 22:56:34 volumio volumio[23947]: SPOTIFY: SPOTIFY VOLUME undefined
Feb 11 22:56:34 volumio volumio[23947]: SPOTIFY: VOLUMIO VOLUME 100
Feb 11 22:56:34 volumio volumio[23947]: info: Aligning Spotify Volume to Volumio Volume
Feb 11 22:56:34 volumio volumio[23947]: info: CoreCommandRouter::volumioGetState
Feb 11 22:56:34 volumio volumio[23947]: info: CorePlayQueue::getTrack 0
Feb 11 22:56:34 volumio volumio[23947]: info: Setting Spotify Volume from Volumio: 100
Feb 11 22:56:35 volumio go-librespot[24314]: time="2026-02-11T22:56:34+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]"
Feb 11 22:56:35 volumio go-librespot[24314]: time="2026-02-11T22:56: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 22:56:35 volumio go-librespot[24314]: time="2026-02-11T22:56: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 22:56:35 volumio go-librespot[24314]: time="2026-02-11T22:56:35+07:00" level=info msg="zeroconf server listening on port 41533"
Feb 11 22:56:35 volumio go-librespot[24314]: time="2026-02-11T22:56:35+07:00" level=debug msg="obtained new client token: AAAEiffi3f/7HeuheW3FGsTTwC0gcJV6+Kt8PvRsGrWnwVvTfW53w6UZ5KeChyF+G1VVcSunrxgQJWg2J8t1IIAbaIMLKNO14JEMZjy7NEdX8ZpBE1TZiM2nwNqr0HGV7vSSKR7z/IsZhY2rX+Ex3OTUwQnrFiC+oS3jWn6XRpZuI6b55pI9EFk16CVRFnPyGugHNaYMgc4FZ/kxVtAqRQsef/o0/J2yzcgC+Q9UtZJAnjiwNYDJ8B8="
Feb 11 22:56:35 volumio go-librespot[24314]: time="2026-02-11T22:56:35+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070"
Feb 11 22:56:35 volumio go-librespot[24314]: time="2026-02-11T22:56:35+07:00" level=debug msg="completed keyexchange"
Feb 11 22:56:35 volumio go-librespot[24314]: time="2026-02-11T22:56:35+07:00" level=debug msg="completed challenge"
Feb 11 22:56:35 volumio volumio[23947]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN
Feb 11 22:56:35 volumio go-librespot[24314]: time="2026-02-11T22:56:35+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 22:56:35 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE
Feb 11 22:56:35 volumio volumio[23947]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Feb 11 22:56:35 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'.
Feb 11 22:56:35 volumio volumio[23947]: Error: socket hang up
Feb 11 22:56:35 volumio volumio[23947]: at connResetException (node:internal/errors:720:14)
Feb 11 22:56:35 volumio volumio[23947]: at Socket.socketOnEnd (node:_http_client:519:23)
Feb 11 22:56:35 volumio volumio[23947]: at Socket.emit (node:events:526:35)
Feb 11 22:56:35 volumio volumio[23947]: at endReadableNT (node:internal/streams/readable:1376:12)
Feb 11 22:56:35 volumio volumio[23947]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) {
Feb 11 22:56:35 volumio volumio[23947]: code: 'ECONNRESET',
Feb 11 22:56:35 volumio volumio[23947]: response: undefined
Feb 11 22:56:35 volumio volumio[23947]: }
Feb 11 22:56:35 volumio volumio[23947]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Feb 11 22:56:37 volumio sudo[24337]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-11 22:55'
Feb 11 22:56:37 volumio sudo[24337]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)"
NAME="Raspbian GNU/Linux"
VERSION_ID="12"
VERSION="12 (bookworm)"
VERSION_CODENAME=bookworm
ID=raspbian
ID_LIKE=debian
HOME_URL="http://www.raspbian.org/"
SUPPORT_URL="http://www.raspbian.org/RaspbianForums"
BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs"
VOLUMIO_BUILD_VERSION="b05a530ca81d05eb9a84d0acf82089f0a60b8ee6"
VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd"
VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2"
VOLUMIO_BE_VERSION="4ad85e2147d972f0b838d33c21382d2d813b2ae8"
VOLUMIO_ARCH="arm"
VOLUMIO_VARIANT="volumio"
VOLUMIO_TEST="FALSE"
VOLUMIO_BUILD_DATE="Thu Dec 25 09:13:19 UTC 2025"
VOLUMIO_VERSION="4.084"
VOLUMIO_HARDWARE="pi"
VOLUMIO_DEVICENAME="Raspberry Pi"
VOLUMIO_HASH="792f09af7488531aecd1aadcaa9b175e"