Feb 12 07:48:00 volumio go-librespot[5069]: time="2026-02-12T07:48: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-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 07:48:00 volumio go-librespot[5069]: time="2026-02-12T07:48:00+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 12 07:48:00 volumio go-librespot[5069]: time="2026-02-12T07:48:00+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 12 07:48:00 volumio go-librespot[5069]: time="2026-02-12T07:48:00+07:00" level=info msg="zeroconf server listening on port 36885" Feb 12 07:48:00 volumio go-librespot[5069]: time="2026-02-12T07:48:00+07:00" level=debug msg="obtained new client token: AAB80+ln2sqpQrT9Qod3pCq8SDvNSX0O68ln1WlwLPdl/T0lssnX7fQX2WplaxK2VhGh8ycnv/Ced/2PlX7SIofem64wLx4HViRiAQij16Q5Mmjaxig04lXpP/jqUF/lp+qUcRZQpzMW2ZkQEhmuATXn6rAeCiw8aUwrKzy922q5/fMC6oIe6M7HoZvIHt69heke1+iT68wrzBWRce7CiaJvzCbhe2el7kzpq7GaVVomwS+/iRM5t3fY/A==" Feb 12 07:48:00 volumio go-librespot[5069]: time="2026-02-12T07:48:00+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 07:48:00 volumio go-librespot[5069]: time="2026-02-12T07:48:00+07:00" level=debug msg="completed keyexchange" Feb 12 07:48:00 volumio go-librespot[5069]: time="2026-02-12T07:48:00+07:00" level=debug msg="completed challenge" Feb 12 07:48:00 volumio go-librespot[5069]: time="2026-02-12T07:48:00+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 12 07:48:00 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 07:48:00 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 07:48:01 volumio volumio[5053]: info: ------------------------------------------- Feb 12 07:48:01 volumio volumio[5053]: info: ----- Volumio3 ---- Feb 12 07:48:01 volumio volumio[5053]: info: ------------------------------------------- Feb 12 07:48:01 volumio volumio[5053]: info: ----- System startup ---- Feb 12 07:48:01 volumio volumio[5053]: info: ------------------------------------------- Feb 12 07:48:02 volumio volumio-remote-updater[643]: [2026-02-12 07:48:02] [connect] Successful connection Feb 12 07:48:02 volumio volumio[5053]: info: MYVOLUMIO Environment detected Feb 12 07:48:02 volumio volumio[5053]: info: Plugin folders cleanup Feb 12 07:48:02 volumio volumio[5053]: info: Scanning into folder /volumio/app/plugins/ Feb 12 07:48:02 volumio volumio[5053]: info: Scanning category audio_interface Feb 12 07:48:02 volumio volumio[5053]: info: Scanning category miscellanea Feb 12 07:48:02 volumio volumio[5053]: info: Scanning category music_service Feb 12 07:48:02 volumio volumio[5053]: info: Scanning category plugins.json Feb 12 07:48:02 volumio volumio[5053]: info: Scanning category system_controller Feb 12 07:48:02 volumio volumio[5053]: info: Scanning category user_interface Feb 12 07:48:02 volumio volumio[5053]: info: Scanning into folder /data/plugins/ Feb 12 07:48:02 volumio volumio[5053]: info: Scanning category music_service Feb 12 07:48:02 volumio volumio[5053]: info: Plugin folders cleanup completed Feb 12 07:48:02 volumio volumio[5053]: info: ------------------------------------------- Feb 12 07:48:02 volumio volumio[5053]: info: ----- Core plugins startup ---- Feb 12 07:48:02 volumio volumio[5053]: info: ------------------------------------------- Feb 12 07:48:02 volumio volumio[5053]: info: Loading plugins from folder /volumio/app/plugins/ Feb 12 07:48:02 volumio volumio[5053]: info: Adding plugin upnp to MyMusic Plugins Feb 12 07:48:02 volumio volumio[5053]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 12 07:48:02 volumio volumio[5053]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 12 07:48:02 volumio volumio[5053]: info: Loading plugins from folder /data/plugins/ Feb 12 07:48:02 volumio volumio[5053]: info: Loading plugin "system"... Feb 12 07:48:02 volumio volumio[5053]: info: Loading plugin "appearance"... Feb 12 07:48:04 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 21. Feb 12 07:48:04 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 07:48:04 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 07:48:04 volumio go-librespot[5089]: go-librespot daemon starting... Feb 12 07:48:04 volumio go-librespot[5090]: time="2026-02-12T07:48:04+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 07:48:04 volumio go-librespot[5090]: time="2026-02-12T07:48:04+07:00" level=debug msg="app state loaded" Feb 12 07:48:04 volumio go-librespot[5090]: time="2026-02-12T07:48:04+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 07:48:04 volumio volumio[5053]: info: Loading plugin "network"... Feb 12 07:48:04 volumio volumio[5053]: info: Refreshing Cached IP Addresses Feb 12 07:48:04 volumio sudo[5099]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 12 07:48:04 volumio sudo[5101]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 12 07:48:04 volumio sudo[5101]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 07:48:04 volumio sudo[5099]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 07:48:04 volumio volumio[5053]: info: Loading plugin "services"... Feb 12 07:48:04 volumio go-librespot[5090]: time="2026-02-12T07:48:04+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 07:48:04 volumio go-librespot[5090]: time="2026-02-12T07:48:04+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 12 07:48:04 volumio go-librespot[5090]: time="2026-02-12T07:48:04+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 12 07:48:04 volumio volumio[5053]: info: Loading plugin "alsa_controller"... Feb 12 07:48:04 volumio sudo[5099]: pam_unix(sudo:session): session closed for user root Feb 12 07:48:04 volumio go-librespot[5090]: time="2026-02-12T07:48:04+07:00" level=info msg="zeroconf server listening on port 44599" Feb 12 07:48:04 volumio sudo[5101]: pam_unix(sudo:session): session closed for user root Feb 12 07:48:04 volumio sudo[5108]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 12 07:48:04 volumio sudo[5108]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 07:48:04 volumio volumio[5053]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 12 07:48:04 volumio volumio[5053]: info: Loading plugin "wizard"... Feb 12 07:48:04 volumio volumio[5053]: info: Loading plugin "networkfs"... Feb 12 07:48:04 volumio go-librespot[5090]: time="2026-02-12T07:48:04+07:00" level=debug msg="obtained new client token: AADMc1d4X5lXn5h42VpVdSWbDeS+eFQuQ8Ju1hTe/ag7kjlqtt42TZiNPEPWBQg3j4sm3o52TZvnNWkx+GKwa/dKh+rv8YxHjpF0MIGOZasj4I766QKU9zkklX69OtQXnaNVlqsGtEqkZm8lUL8qnJ0kmajtZmwcc6wiklyxWqCzy9nYzW1sE/4QXhriY4h1nMeIJppQpmgbL+7P9PwyKJKQ7+jvnGtHA23+D5PJr5mbIztuzBVlpp3osQ==" Feb 12 07:48:04 volumio volumio[5053]: info: Starting Udev Watcher for removable devices Feb 12 07:48:04 volumio volumio[5053]: info: Ignoring mount for partition: boot Feb 12 07:48:04 volumio volumio[5053]: info: Ignoring mount for partition: volumio Feb 12 07:48:04 volumio volumio[5053]: info: Ignoring mount for partition: volumio_data Feb 12 07:48:04 volumio volumio[5053]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 12 07:48:04 volumio volumio[5053]: info: Loading plugin "volumio_command_line_client"... Feb 12 07:48:05 volumio volumio[5053]: info: Loading plugin "upnp"... Feb 12 07:48:05 volumio volumio[5053]: info: [1770857285005] Starting Upmpd Daemon Feb 12 07:48:05 volumio volumio[5053]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 12 07:48:05 volumio volumio[5053]: info: Loading plugin "my_music"... Feb 12 07:48:05 volumio go-librespot[5090]: time="2026-02-12T07:48:05+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 07:48:05 volumio volumio[5053]: info: Loading plugin "mpd"... Feb 12 07:48:05 volumio go-librespot[5090]: time="2026-02-12T07:48:05+07:00" level=debug msg="completed keyexchange" Feb 12 07:48:05 volumio go-librespot[5090]: time="2026-02-12T07:48:05+07:00" level=debug msg="completed challenge" Feb 12 07:48:05 volumio go-librespot[5090]: time="2026-02-12T07:48:05+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 12 07:48:05 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 07:48:05 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 07:48:05 volumio volumio[5053]: info: Loading plugin "upnp_browser"... Feb 12 07:48:07 volumio sudo[5108]: pam_unix(sudo:session): session closed for user root Feb 12 07:48:08 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 22. Feb 12 07:48:08 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 07:48:08 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 07:48:08 volumio go-librespot[5132]: go-librespot daemon starting... Feb 12 07:48:08 volumio go-librespot[5133]: time="2026-02-12T07:48:08+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 07:48:08 volumio go-librespot[5133]: time="2026-02-12T07:48:08+07:00" level=debug msg="app state loaded" Feb 12 07:48:08 volumio go-librespot[5133]: time="2026-02-12T07:48:08+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 07:48:08 volumio volumio[5053]: info: Starting UPNP Browser Feb 12 07:48:08 volumio volumio[5053]: info: Loading plugin "alarm-clock"... Feb 12 07:48:08 volumio volumio[5053]: info: Loading plugin "airplay_emulation"... Feb 12 07:48:08 volumio go-librespot[5133]: time="2026-02-12T07:48:08+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 07:48:08 volumio go-librespot[5133]: time="2026-02-12T07:48:08+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 12 07:48:08 volumio go-librespot[5133]: time="2026-02-12T07:48:08+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 12 07:48:08 volumio volumio[5053]: info: Starting Shairport Sync Feb 12 07:48:08 volumio volumio[5053]: info: Loading plugin "last_100"... Feb 12 07:48:08 volumio go-librespot[5133]: time="2026-02-12T07:48:08+07:00" level=info msg="zeroconf server listening on port 42381" Feb 12 07:48:08 volumio volumio[5053]: info: Loading plugin "webradio"... Feb 12 07:48:09 volumio volumio[5053]: info: Loading plugin "i2s_dacs"... Feb 12 07:48:09 volumio volumio[5053]: info: Loading plugin "volumiodiscovery"... Feb 12 07:48:09 volumio go-librespot[5133]: time="2026-02-12T07:48:09+07:00" level=debug msg="obtained new client token: AACqYrGGKuee4A4d8p1zBqjMb8n4XP/xul+tPUHNi3LYvbswyuowO1WU+fRNuMdoLWBEbllvtRPbgIHjhF0NmZC5E12rJP1G6j6qGQSTNDQFB7iFd7+daNtH/x2Zxc5hGVwJfLef/k/SQZGag4g3CKX1BWpzBumZ9A/bDqmH2vBXJNr8LjCsWa3Y2flswJ8GTzWwnkAdIxwC6TI8vR9smprgUdST5YZyQ3KENPXTfa16r4yxeZHfIx4=" Feb 12 07:48:09 volumio volumio[5053]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 12 07:48:09 volumio node[5053]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 12 07:48:09 volumio volumio[5053]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 12 07:48:09 volumio node[5053]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 12 07:48:09 volumio volumio[5053]: *** WARNING *** For more information see Feb 12 07:48:09 volumio node[5053]: *** WARNING *** For more information see Feb 12 07:48:09 volumio volumio[5053]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 12 07:48:09 volumio node[5053]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 12 07:48:09 volumio volumio[5053]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 12 07:48:09 volumio node[5053]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 12 07:48:09 volumio volumio[5053]: *** WARNING *** For more information see Feb 12 07:48:09 volumio volumio[5053]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 12 07:48:09 volumio node[5053]: *** WARNING *** For more information see Feb 12 07:48:09 volumio volumio[5053]: info: Discovery: Started advertising with name: Volumio Feb 12 07:48:09 volumio volumio[5053]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 12 07:48:09 volumio volumio[5053]: info: Loading plugin "spop"... Feb 12 07:48:09 volumio go-librespot[5133]: time="2026-02-12T07:48:09+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 07:48:09 volumio go-librespot[5133]: time="2026-02-12T07:48:09+07:00" level=debug msg="completed keyexchange" Feb 12 07:48:09 volumio go-librespot[5133]: time="2026-02-12T07:48:09+07:00" level=debug msg="completed challenge" Feb 12 07:48:09 volumio go-librespot[5133]: time="2026-02-12T07:48:09+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 12 07:48:09 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 07:48:09 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 07:48:11 volumio volumio[5053]: info: Loading plugin "ytcr"... Feb 12 07:48:12 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 23. Feb 12 07:48:12 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 07:48:12 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 07:48:12 volumio go-librespot[5147]: go-librespot daemon starting... Feb 12 07:48:12 volumio go-librespot[5148]: time="2026-02-12T07:48:12+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 07:48:12 volumio go-librespot[5148]: time="2026-02-12T07:48:12+07:00" level=debug msg="app state loaded" Feb 12 07:48:12 volumio go-librespot[5148]: time="2026-02-12T07:48:12+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 07:48:13 volumio go-librespot[5148]: time="2026-02-12T07:48:13+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 07:48:13 volumio go-librespot[5148]: time="2026-02-12T07:48:13+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 12 07:48:13 volumio go-librespot[5148]: time="2026-02-12T07:48:13+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 12 07:48:13 volumio go-librespot[5148]: time="2026-02-12T07:48:13+07:00" level=info msg="zeroconf server listening on port 43419" Feb 12 07:48:13 volumio go-librespot[5148]: time="2026-02-12T07:48:13+07:00" level=debug msg="obtained new client token: AABAOdU0iKDLrGq+FIFGLD73ChM0giqml1eCSz5a0KGj4dNIlkRqwYapJvq+RmjPwvXQULiSdU3vbBLja8z9sIGgE/Oq7kREeqiGKwE3akEI26x5opIkRxYbbo0KnkSMgDf6Ip2VIqI455b6fieoS3qkxEfeyNvcRyI9TWDJe74oNLzdbXUu6UNINDk9jsohLNhaSHRTJDRnQcq62AqachxEIJ9eIsdnGZMTZDI/qDMEA0MSWiKEecncXA==" Feb 12 07:48:13 volumio go-librespot[5148]: time="2026-02-12T07:48:13+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 07:48:13 volumio go-librespot[5148]: time="2026-02-12T07:48:13+07:00" level=debug msg="completed keyexchange" Feb 12 07:48:13 volumio go-librespot[5148]: time="2026-02-12T07:48:13+07:00" level=debug msg="completed challenge" Feb 12 07:48:13 volumio volumio[5053]: info: Loading plugin "ytmusic"... Feb 12 07:48:13 volumio go-librespot[5148]: time="2026-02-12T07:48:13+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 12 07:48:13 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 07:48:13 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 07:48:14 volumio volumio-remote-updater[643]: [2026-02-12 07:48:14] [connect] Successful connection Feb 12 07:48:14 volumio volumio[5053]: info: Loading plugin "outputs"... Feb 12 07:48:14 volumio volumio[5053]: info: Loading plugin "albumart"... Feb 12 07:48:14 volumio volumio[5053]: info: Plugin example_plugin is not enabled Feb 12 07:48:14 volumio volumio[5053]: info: Loading plugin "inputs"... Feb 12 07:48:14 volumio volumio[5053]: info: Loading plugin "updater_comm"... Feb 12 07:48:15 volumio volumio[5053]: info: Plugin mpdemulation is not enabled Feb 12 07:48:15 volumio volumio[5053]: info: Loading plugin "rest_api"... Feb 12 07:48:15 volumio volumio[5053]: info: Loading plugin "websocket"... Feb 12 07:48:15 volumio volumio[5053]: info: Starting Socket.io Server version 1.7.4 Feb 12 07:48:15 volumio volumio[5053]: info: Loading plugin "RoonBridge"... Feb 12 07:48:15 volumio volumio[5053]: info: Applying required configuration parameters for plugin RoonBridge Feb 12 07:48:15 volumio volumio[5053]: info: Loading i18n strings for locale en Feb 12 07:48:15 volumio volumio[5053]: Updating browse sources language Feb 12 07:48:15 volumio volumio[5053]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 07:48:15 volumio volumio[5170]: Forking 3 albumart workers Feb 12 07:48:16 volumio volumio[5053]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 12 07:48:16 volumio volumio[5053]: info: CoreCommandRouter::initPlayerControls Feb 12 07:48:16 volumio volumio[5053]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 07:48:16 volumio volumio[5053]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 07:48:16 volumio volumio[5053]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 07:48:16 volumio volumio[5053]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 07:48:16 volumio volumio[5053]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 07:48:16 volumio volumio[5053]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 07:48:16 volumio volumio[5053]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 07:48:16 volumio volumio[5053]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 07:48:16 volumio volumio[5053]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 12 07:48:16 volumio volumio[5053]: Express server listening on port 3000 Feb 12 07:48:16 volumio volumio[5053]: [Metrics] WebUI: 16s 144.49ms Feb 12 07:48:16 volumio volumio[5053]: info: CoreStateMachine::resetVolumioState Feb 12 07:48:16 volumio volumio[5053]: info: CoreStateMachine::getcurrentVolume Feb 12 07:48:16 volumio volumio[5053]: info: CoreCommandRouter::volumioRetrievevolume Feb 12 07:48:16 volumio sudo[5215]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 12 07:48:16 volumio sudo[5215]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 07:48:16 volumio sudo[5217]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 12 07:48:16 volumio sudo[5217]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 07:48:16 volumio sudo[5215]: pam_unix(sudo:session): session closed for user root Feb 12 07:48:16 volumio sudo[5217]: pam_unix(sudo:session): session closed for user root Feb 12 07:48:16 volumio volumio[5053]: info: Volumio Network Manager: Network status updated: 1 Feb 12 07:48:16 volumio volumio[5053]: info: VolumeController:: Volume=100 Mute =false Feb 12 07:48:16 volumio volumio[5053]: info: CoreStateMachine::pushState Feb 12 07:48:16 volumio volumio[5053]: info: CorePlayQueue::getTrack 0 Feb 12 07:48:16 volumio volumio[5053]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 12 07:48:16 volumio volumio[5053]: info: CoreCommandRouter::volumioPushState Feb 12 07:48:16 volumio volumio[5053]: info: CoreStateMachine::updateTrackBlock Feb 12 07:48:16 volumio volumio[5053]: info: CorePlayQueue::getTrackBlock Feb 12 07:48:16 volumio volumio[5053]: info: CoreCommandRouter::volumioRetrievevolume Feb 12 07:48:16 volumio volumio-remote-updater[643]: [2026-02-12 07:48:16] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770857294 101 Feb 12 07:48:16 volumio volumio[5053]: 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 12 07:48:16 volumio volumio[5053]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 07:48:16 volumio volumio[5053]: info: Reloading queue from file Feb 12 07:48:16 volumio volumio[5053]: info: CoreStateMachine::setRepeat null single undefined Feb 12 07:48:16 volumio volumio[5053]: info: CoreStateMachine::pushState Feb 12 07:48:16 volumio volumio[5053]: info: CorePlayQueue::getTrack 0 Feb 12 07:48:16 volumio volumio[5053]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 12 07:48:16 volumio volumio[5053]: info: CoreCommandRouter::volumioPushState Feb 12 07:48:17 volumio volumio[5053]: info: CoreStateMachine::setRandom null Feb 12 07:48:17 volumio volumio[5053]: info: CoreStateMachine::pushState Feb 12 07:48:17 volumio volumio[5053]: info: CorePlayQueue::getTrack 0 Feb 12 07:48:17 volumio volumio[5053]: info: CoreCommandRouter::volumioPushState Feb 12 07:48:17 volumio volumio[5053]: info: Setting Device type: Raspberry PI Feb 12 07:48:17 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 24. Feb 12 07:48:17 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 07:48:17 volumio volumio[5053]: info: Completed loading Core Plugins Feb 12 07:48:17 volumio volumio[5053]: info: Preparing to generate the ALSA configuration file Feb 12 07:48:17 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 07:48:17 volumio go-librespot[5228]: go-librespot daemon starting... Feb 12 07:48:17 volumio go-librespot[5229]: time="2026-02-12T07:48:17+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 07:48:17 volumio go-librespot[5229]: time="2026-02-12T07:48:17+07:00" level=debug msg="app state loaded" Feb 12 07:48:17 volumio go-librespot[5229]: time="2026-02-12T07:48:17+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 07:48:17 volumio volumio[5053]: info: VolumeController:: Volume=100 Mute =false Feb 12 07:48:17 volumio volumio[5053]: info: CoreStateMachine::pushState Feb 12 07:48:17 volumio volumio[5053]: info: CorePlayQueue::getTrack 0 Feb 12 07:48:17 volumio volumio[5053]: info: CoreCommandRouter::volumioPushState Feb 12 07:48:17 volumio volumio[5053]: info: Asound.conf file unchanged, so no further update is needed Feb 12 07:48:17 volumio volumio[5053]: info: Output device has changed, restarting MPD Feb 12 07:48:17 volumio sudo[5237]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 12 07:48:17 volumio sudo[5237]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 07:48:17 volumio volumio[5053]: info: Output device has changed, restarting Shairport Sync Feb 12 07:48:17 volumio volumio[5053]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 07:48:17 volumio volumio[5053]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 07:48:17 volumio sudo[5240]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 12 07:48:17 volumio sudo[5237]: pam_unix(sudo:session): session closed for user root Feb 12 07:48:17 volumio sudo[5240]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 07:48:17 volumio sudo[5240]: pam_unix(sudo:session): session closed for user root Feb 12 07:48:17 volumio sudo[5242]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 12 07:48:17 volumio sudo[5242]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 07:48:17 volumio volumio[5053]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 12 07:48:17 volumio volumio[5053]: info: ___________ START PLUGINS ___________ Feb 12 07:48:17 volumio volumio[5053]: info: ControllerMpd::onStart: Initializing MPD Feb 12 07:48:17 volumio volumio[5053]: info: Creating MPD Configuration file Feb 12 07:48:17 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 12 07:48:17 volumio volumio[5053]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 12 07:48:17 volumio volumio[5053]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 12 07:48:17 volumio volumio[5053]: info: [1770857297758] CoreMusicLibrary::Adding element Media Servers Feb 12 07:48:17 volumio volumio[5053]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 07:48:17 volumio sudo[5252]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 12 07:48:17 volumio sudo[5252]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 07:48:17 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 12 07:48:17 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 12 07:48:17 volumio systemd[1]: mpd.service: Consumed 7.190s CPU time. Feb 12 07:48:17 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 12 07:48:17 volumio sudo[5254]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 12 07:48:17 volumio sudo[5254]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 07:48:17 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 12 07:48:17 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 12 07:48:17 volumio volumio[5053]: info: UPNP Browser: Client initialized successfully Feb 12 07:48:17 volumio sudo[5252]: pam_unix(sudo:session): session closed for user root Feb 12 07:48:17 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 12 07:48:17 volumio volumio[5053]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 07:48:17 volumio go-librespot[5229]: time="2026-02-12T07:48:17+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 07:48:17 volumio go-librespot[5229]: time="2026-02-12T07:48:17+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 12 07:48:17 volumio go-librespot[5229]: time="2026-02-12T07:48:17+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 12 07:48:18 volumio volumio[5053]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 07:48:18 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 12 07:48:18 volumio go-librespot[5229]: time="2026-02-12T07:48:18+07:00" level=info msg="zeroconf server listening on port 42731" Feb 12 07:48:18 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 12 07:48:18 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 12 07:48:18 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 12 07:48:18 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 12 07:48:18 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 12 07:48:18 volumio volumio[5053]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 12 07:48:18 volumio volumio[5053]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 07:48:18 volumio volumio[5053]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 07:48:18 volumio volumio[5053]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 12 07:48:18 volumio volumio[5053]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 12 07:48:18 volumio volumio[5053]: info: [1770857298204] CoreMusicLibrary::Adding element Last_100 Feb 12 07:48:18 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 12 07:48:18 volumio volumio[5053]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 07:48:18 volumio volumio[5053]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 12 07:48:18 volumio volumio[5053]: info: [1770857298230] CoreMusicLibrary::Adding element Webradio Feb 12 07:48:18 volumio volumio[5053]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 07:48:18 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 12 07:48:18 volumio go-librespot[5229]: time="2026-02-12T07:48:18+07:00" level=debug msg="obtained new client token: AAA4RwKyMtv9TDmiifsVNTkQdqcxbZsq8K0zO5ZfFbc4HfhDLTjtaxaUUTdvugHnTqR9H3ykdURb6ebrRoI+xmyZfwnCwAgLnGBfCPwS2CFo46JHuAZY7TkzFjjeOXEZMfl39GP7nPYkjn+9+oFhAghFFPulCdv8AkWnbT7qFw+5J/C1J41qf/gidbdmJ9ffGZfHGTXysV3QTBVOaG7OXhDzxqEqiKd0yC/UqZEaJSi1Vp/rqGcGcGs=" Feb 12 07:48:18 volumio volumio[5053]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 12 07:48:18 volumio volumio[5053]: info: Initializing BBC Radios Feb 12 07:48:18 volumio go-librespot[5229]: time="2026-02-12T07:48:18+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 07:48:18 volumio go-librespot[5229]: time="2026-02-12T07:48:18+07:00" level=debug msg="completed keyexchange" Feb 12 07:48:18 volumio go-librespot[5229]: time="2026-02-12T07:48:18+07:00" level=debug msg="completed challenge" Feb 12 07:48:18 volumio volumio[5053]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 12 07:48:18 volumio volumio[5053]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 07:48:18 volumio go-librespot[5229]: time="2026-02-12T07:48: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 12 07:48:18 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 07:48:18 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 07:48:18 volumio volumio[5053]: info: Creating Spotify config file Feb 12 07:48:18 volumio volumio[5053]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 07:48:18 volumio sudo[5268]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 12 07:48:18 volumio sudo[5268]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 12 07:48:18 volumio sudo[5268]: pam_unix(sudo:session): session closed for user root Feb 12 07:48:19 volumio volumio[5182]: Starting albumart workers Feb 12 07:48:19 volumio volumio[5181]: Starting albumart workers Feb 12 07:48:19 volumio volumio[5053]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 12 07:48:19 volumio volumio[5053]: info: [1770857299762] CoreMusicLibrary::Adding element YouTube Music Feb 12 07:48:19 volumio volumio[5180]: Starting albumart workers Feb 12 07:48:19 volumio volumio[5053]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 07:48:19 volumio volumio[5053]: Cannot find translation for source YouTube Music Feb 12 07:48:19 volumio volumio[5053]: info: Volumio Calling Home Feb 12 07:48:19 volumio sudo[5285]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 12 07:48:19 volumio sudo[5285]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 07:48:20 volumio sudo[5285]: pam_unix(sudo:session): session closed for user root Feb 12 07:48:20 volumio volumio[5053]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 12 07:48:20 volumio volumio[5053]: info: Discovery: Found device Volumio Feb 12 07:48:20 volumio volumio[5053]: info: CoreCommandRouter::volumioGetState Feb 12 07:48:20 volumio volumio[5053]: info: CorePlayQueue::getTrack 0 Feb 12 07:48:20 volumio volumio[5053]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 12 07:48:20 volumio volumio[5053]: info: Discovery: Found device Volumio Feb 12 07:48:20 volumio volumio[5053]: info: CoreCommandRouter::volumioGetState Feb 12 07:48:20 volumio volumio[5053]: info: CorePlayQueue::getTrack 0 Feb 12 07:48:20 volumio volumio[5053]: info: MPD Permissions set Feb 12 07:48:20 volumio volumio[5053]: info: MPD Permissions set Feb 12 07:48:20 volumio volumio[5053]: info: Upmpdcli Daemon Started Feb 12 07:48:21 volumio volumio[5053]: info: Volumio called home Feb 12 07:48:21 volumio volumio[5053]: info: Spotify config file written Feb 12 07:48:21 volumio sudo[5300]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 12 07:48:21 volumio volumio[5053]: 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 12 07:48:21 volumio sudo[5300]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 07:48:21 volumio volumio[5053]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 07:48:21 volumio volumio[5053]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 07:48:21 volumio volumio[5053]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 07:48:21 volumio volumio[5053]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 07:48:21 volumio volumio[5053]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 07:48:21 volumio volumio[5053]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 07:48:21 volumio volumio[5053]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 07:48:21 volumio volumio[5053]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 07:48:21 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 07:48:21 volumio volumio[5053]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 07:48:21 volumio volumio[5053]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 07:48:21 volumio volumio[5053]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 07:48:21 volumio volumio[5053]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 07:48:21 volumio volumio[5053]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 07:48:21 volumio volumio[5053]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 07:48:21 volumio volumio[5053]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 07:48:21 volumio volumio[5053]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 07:48:21 volumio volumio[5053]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 07:48:21 volumio volumio[5053]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 07:48:21 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 07:48:21 volumio volumio[5053]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 07:48:21 volumio volumio[5053]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 07:48:21 volumio go-librespot[5310]: go-librespot daemon starting... Feb 12 07:48:21 volumio volumio[5053]: info: No need to fix Spotify hosts Feb 12 07:48:21 volumio sudo[5300]: pam_unix(sudo:session): session closed for user root Feb 12 07:48:21 volumio go-librespot[5316]: time="2026-02-12T07:48:21+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 07:48:21 volumio go-librespot[5316]: time="2026-02-12T07:48:21+07:00" level=debug msg="app state loaded" Feb 12 07:48:21 volumio go-librespot[5316]: time="2026-02-12T07:48:21+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 07:48:22 volumio go-librespot[5316]: time="2026-02-12T07:48:22+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 07:48:22 volumio go-librespot[5316]: time="2026-02-12T07:48:22+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 12 07:48:22 volumio go-librespot[5316]: time="2026-02-12T07:48:22+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 12 07:48:22 volumio go-librespot[5316]: time="2026-02-12T07:48:22+07:00" level=info msg="zeroconf server listening on port 34131" Feb 12 07:48:22 volumio volumio[5053]: info: Starting Shairport Sync Feb 12 07:48:22 volumio volumio[5053]: info: Starting Shairport Sync Feb 12 07:48:22 volumio volumio[5053]: info: Starting Shairport Sync Feb 12 07:48:22 volumio sudo[5330]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 12 07:48:22 volumio sudo[5330]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 07:48:22 volumio go-librespot[5316]: time="2026-02-12T07:48:22+07:00" level=debug msg="obtained new client token: AABwO3wBHTVSB3gbqh+EIxHoQNbFsHOTTNQ9OsJOpCTfiFyiNNNRvZTbHIMuCKPSZtCyMt7li9Cly9XOR5TXe1tY+c95nHJac0nHg0tZtdHsO1svDIA+aVE6XysxSHUQK2rVMmXZ5zS2J4q9abD5w2TAeKI6aPCfzLQSGem61X2TwxfdtWDc/qwIjUB0DaYDBI6cuc/U+0kaIN9uhMarf8Omc2dI+LhzS6p/+Ok4bDjD2TffD9u3H+liYA==" Feb 12 07:48:22 volumio sudo[5332]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 12 07:48:22 volumio sudo[5332]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 07:48:22 volumio go-librespot[5316]: time="2026-02-12T07:48:22+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 12 07:48:22 volumio sudo[5335]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 12 07:48:22 volumio sudo[5335]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 07:48:22 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 12 07:48:22 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 12 07:48:22 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 12 07:48:22 volumio systemd[1]: shairport-sync.service: Consumed 2.375s CPU time. Feb 12 07:48:22 volumio go-librespot[5316]: time="2026-02-12T07:48:22+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 12 07:48:22 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 12 07:48:22 volumio go-librespot[5316]: time="2026-02-12T07:48:22+07:00" level=debug msg="completed keyexchange" Feb 12 07:48:22 volumio go-librespot[5316]: time="2026-02-12T07:48:22+07:00" level=debug msg="completed challenge" Feb 12 07:48:22 volumio volumio[5053]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 12 07:48:22 volumio volumio[5053]: SPOTIFY: BQDJCyPQKuQinJz_MQsEkgbDhs4lNo97vof9S_PjcsyMOUvKXK2yHkq-4_mL5UbES-xwhYI7UWb4aa_-GYaUpASRxnesIZD_iqsxDT61otDNd8G1ZmSqrLqP05-r_KDGAdK5I-C6r5g9f1f6MqK6YePQEtrZ_bbvpPTYzu5FilQLbPrmCNCQpisgMQuuPAzPC3JMVcwv7g_XXAEtfiC350xhp96aD71_TrAkc9U0q6S7bCYK1673A5q7ctpp89Crp9wixAN042LS_b9YeyxdzDI3by1IZpeM7eLROJMNxSLOnLSd3axN1sho Feb 12 07:48:22 volumio volumio[5053]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 12 07:48:22 volumio volumio[5053]: info: New Spotify access token = BQDJCyPQKuQinJz_MQsEkgbDhs4lNo97vof9S_PjcsyMOUvKXK2yHkq-4_mL5UbES-xwhYI7UWb4aa_-GYaUpASRxnesIZD_iqsxDT61otDNd8G1ZmSqrLqP05-r_KDGAdK5I-C6r5g9f1f6MqK6YePQEtrZ_bbvpPTYzu5FilQLbPrmCNCQpisgMQuuPAzPC3JMVcwv7g_XXAEtfiC350xhp96aD71_TrAkc9U0q6S7bCYK1673A5q7ctpp89Crp9wixAN042LS_b9YeyxdzDI3by1IZpeM7eLROJMNxSLOnLSd3axN1sho Feb 12 07:48:22 volumio volumio[5053]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 12 07:48:22 volumio sudo[5330]: pam_unix(sudo:session): session closed for user root Feb 12 07:48:22 volumio volumio[5053]: info: CoreCommandRouter::volumioGetState Feb 12 07:48:22 volumio volumio[5053]: info: CorePlayQueue::getTrack 0 Feb 12 07:48:22 volumio go-librespot[5316]: time="2026-02-12T07:48: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 12 07:48:22 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 07:48:22 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 07:48:22 volumio sudo[5332]: pam_unix(sudo:session): session closed for user root Feb 12 07:48:22 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 12 07:48:22 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 12 07:48:22 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 12 07:48:22 volumio volumio[5053]: info: Shairport-Sync Started Feb 12 07:48:22 volumio volumio[5053]: Error adding Membership: Error: addMembership EINVAL Feb 12 07:48:22 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 12 07:48:22 volumio sudo[5335]: pam_unix(sudo:session): session closed for user root Feb 12 07:48:22 volumio volumio[5053]: info: Shairport-Sync Started Feb 12 07:48:23 volumio volumio[5053]: info: Shairport-Sync Started Feb 12 07:48:23 volumio volumio[5053]: 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 12 07:48:23 volumio volumio[5053]: info: Spotify Successfully logged in Feb 12 07:48:23 volumio volumio[5053]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 12 07:48:23 volumio volumio[5053]: info: [1770857303290] CoreMusicLibrary::Adding element Spotify Feb 12 07:48:23 volumio volumio[5053]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 07:48:23 volumio volumio[5053]: Cannot find translation for source YouTube Music Feb 12 07:48:23 volumio volumio[5053]: Cannot find translation for source Spotify Feb 12 07:48:24 volumio volumio[5053]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 12 07:48:24 volumio volumio[5053]: info: CoreCommandRouter::volumioRetrievevolume Feb 12 07:48:24 volumio volumio[5053]: info: VolumeController:: Volume=100 Mute =false Feb 12 07:48:24 volumio volumio[5053]: info: CoreCommandRouter::volumioGetState Feb 12 07:48:24 volumio volumio[5053]: info: CorePlayQueue::getTrack 0 Feb 12 07:48:24 volumio volumio[5053]: info: CoreStateMachine::pushState Feb 12 07:48:24 volumio volumio[5053]: info: CorePlayQueue::getTrack 0 Feb 12 07:48:24 volumio volumio[5053]: info: CoreCommandRouter::volumioPushState Feb 12 07:48:25 volumio volumio[5053]: info: go-librespot daemon successfully initialized Feb 12 07:48:25 volumio mpd[5283]: 2026-02-12T07:48:25 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 12 07:48:25 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 12 07:48:25 volumio sudo[5254]: pam_unix(sudo:session): session closed for user root Feb 12 07:48:25 volumio sudo[5242]: pam_unix(sudo:session): session closed for user root Feb 12 07:48:25 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 25. Feb 12 07:48:25 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 07:48:25 volumio volumio[5053]: error: MPD error: The expression evaluated to a falsy value: Feb 12 07:48:25 volumio volumio[5053]: assert.ok(self.idling) Feb 12 07:48:25 volumio volumio[5053]: error: The expression evaluated to a falsy value: Feb 12 07:48:25 volumio volumio[5053]: assert.ok(self.idling) Feb 12 07:48:25 volumio volumio[5053]: error: updateQueue error: null Feb 12 07:48:25 volumio volumio[5053]: info: MPD running with PID5283 Feb 12 07:48:25 volumio volumio[5053]: ,establishing connection Feb 12 07:48:25 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 07:48:25 volumio go-librespot[5384]: go-librespot daemon starting... Feb 12 07:48:25 volumio go-librespot[5385]: time="2026-02-12T07:48:25+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 07:48:25 volumio go-librespot[5385]: time="2026-02-12T07:48:25+07:00" level=debug msg="app state loaded" Feb 12 07:48:25 volumio go-librespot[5385]: time="2026-02-12T07:48:25+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 07:48:25 volumio volumio[5053]: info: Completed starting Core Plugins Feb 12 07:48:25 volumio volumio[5053]: info: ------------------------------------------- Feb 12 07:48:25 volumio volumio[5053]: info: ----- MyVolumio plugins startup ---- Feb 12 07:48:25 volumio volumio[5053]: info: ------------------------------------------- Feb 12 07:48:25 volumio volumio[5053]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 12 07:48:25 volumio volumio[5053]: error: updateQueue error: null Feb 12 07:48:26 volumio go-librespot[5385]: time="2026-02-12T07:48: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-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 07:48:26 volumio go-librespot[5385]: time="2026-02-12T07:48:26+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 12 07:48:26 volumio go-librespot[5385]: time="2026-02-12T07:48:26+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 12 07:48:26 volumio go-librespot[5385]: time="2026-02-12T07:48:26+07:00" level=info msg="zeroconf server listening on port 46101" Feb 12 07:48:26 volumio go-librespot[5385]: time="2026-02-12T07:48:26+07:00" level=debug msg="obtained new client token: AAApIz9mOvzYaC3O6ko//dRPC3+LK/j9SgtvCss1+/8HDw2CB/+Y+JHdHpTMtUR+bMKiRf3s+AGhxU1DsekcBRTr0k81SpRArkTleMBndWI/aE5aDzGAzch9D4DqMGYNAOvJoAUX8xh0YTYlvd5U3yTCd/xrMLfcJuzqlDbh/9z/kGLo184UKCAAOLitQQDGcu4TPwZ3FDVZgoo8t76RaB4hBX/tJE5U2r5FIFn+eTSTGTWR5F+9uwmyHQ==" Feb 12 07:48:26 volumio go-librespot[5385]: time="2026-02-12T07:48:26+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 07:48:27 volumio go-librespot[5385]: time="2026-02-12T07:48:27+07:00" level=debug msg="completed keyexchange" Feb 12 07:48:27 volumio go-librespot[5385]: time="2026-02-12T07:48:27+07:00" level=debug msg="completed challenge" Feb 12 07:48:27 volumio go-librespot[5385]: time="2026-02-12T07:48:27+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 12 07:48:27 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 07:48:27 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 07:48:28 volumio volumio[5053]: info: Initializing connection to go-librespot Websocket Feb 12 07:48:28 volumio volumio[5053]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 12 07:48:30 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 26. Feb 12 07:48:30 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 07:48:30 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 07:48:30 volumio go-librespot[5394]: go-librespot daemon starting... Feb 12 07:48:30 volumio go-librespot[5395]: time="2026-02-12T07:48:30+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 07:48:30 volumio go-librespot[5395]: time="2026-02-12T07:48:30+07:00" level=debug msg="app state loaded" Feb 12 07:48:30 volumio go-librespot[5395]: time="2026-02-12T07:48:30+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 07:48:30 volumio volumio[5053]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 12 07:48:30 volumio go-librespot[5395]: time="2026-02-12T07:48: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 07:48:30 volumio go-librespot[5395]: time="2026-02-12T07:48:30+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 12 07:48:30 volumio go-librespot[5395]: time="2026-02-12T07:48:30+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 12 07:48:30 volumio go-librespot[5395]: time="2026-02-12T07:48:30+07:00" level=info msg="zeroconf server listening on port 45859" Feb 12 07:48:31 volumio go-librespot[5395]: time="2026-02-12T07:48:31+07:00" level=debug msg="obtained new client token: AAD0Rjf6jPMlQnaraO7SDhemAPeCnfXzF/KtGZ9Bv5aJovqyX42ibazdwhDu76Rxuvkbw13trOr8m1gaG5KhczdznZTNF2ZcBGaW08nciLxYCLakVJV4rmmjj28Q1qkL1BB8Md0I7M+7m0YLHVT1muAS1MrpyBo9y3lRGh8tZr5w0g0PwOC0kw4KE3sbaHk/4R+0k04IZS3bL0QkczExuDzk4fzZX2MIeJzdPzd9pj7QZgsMExKGq6I=" Feb 12 07:48:31 volumio go-librespot[5395]: time="2026-02-12T07:48:31+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 07:48:31 volumio volumio[5053]: info: Initializing connection to go-librespot Websocket Feb 12 07:48:31 volumio go-librespot[5395]: time="2026-02-12T07:48:31+07:00" level=debug msg="new websocket client" Feb 12 07:48:31 volumio volumio[5053]: info: Connection to go-librespot Websocket established Feb 12 07:48:31 volumio go-librespot[5395]: time="2026-02-12T07:48:31+07:00" level=debug msg="completed keyexchange" Feb 12 07:48:31 volumio go-librespot[5395]: time="2026-02-12T07:48:31+07:00" level=debug msg="completed challenge" Feb 12 07:48:31 volumio go-librespot[5395]: time="2026-02-12T07:48: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 12 07:48:31 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 07:48:31 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 07:48:31 volumio volumio[5053]: info: Connection to go-librespot Websocket closed Feb 12 07:48:34 volumio volumio[5053]: info: Getting Spotify volume Feb 12 07:48:34 volumio volumio[5053]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 12 07:48:34 volumio volumio[5053]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 12 07:48:34 volumio volumio[5053]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 12 07:48:34 volumio volumio[5053]: errno: -111, Feb 12 07:48:34 volumio volumio[5053]: code: 'ECONNREFUSED', Feb 12 07:48:34 volumio volumio[5053]: syscall: 'connect', Feb 12 07:48:34 volumio volumio[5053]: address: '127.0.0.1', Feb 12 07:48:34 volumio volumio[5053]: port: 9879, Feb 12 07:48:34 volumio volumio[5053]: response: undefined Feb 12 07:48:34 volumio volumio[5053]: } Feb 12 07:48:34 volumio volumio[5053]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 12 07:48:34 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 27. Feb 12 07:48:34 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 07:48:34 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 07:48:34 volumio go-librespot[5415]: go-librespot daemon starting... Feb 12 07:48:34 volumio go-librespot[5416]: time="2026-02-12T07:48:34+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 07:48:34 volumio go-librespot[5416]: time="2026-02-12T07:48:34+07:00" level=debug msg="app state loaded" Feb 12 07:48:34 volumio go-librespot[5416]: time="2026-02-12T07:48:34+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 07:48:35 volumio go-librespot[5416]: time="2026-02-12T07:48: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 12 07:48:35 volumio go-librespot[5416]: time="2026-02-12T07:48: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 12 07:48:35 volumio go-librespot[5416]: time="2026-02-12T07:48: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 12 07:48:35 volumio go-librespot[5416]: time="2026-02-12T07:48:35+07:00" level=info msg="zeroconf server listening on port 45137" Feb 12 07:48:35 volumio go-librespot[5416]: time="2026-02-12T07:48:35+07:00" level=debug msg="obtained new client token: AABrMvVdUUtKh3vvw158P6MkbdM8AH62J6AwWKmVZ9LL9XQHRrg+F6dNSXuStlatvzaF6s+3oph9KZwzQ0Zt6KTvmG4E/OhMuxLMYrBJr4zecdgLbZbkDgpPoHe1lLBQtCEDkXsd5hFj6H1A28tmmIiiT3j2/obuiFtsLPmyIwC0HQB7pMrRGE4EHc3jgh94edx6Ymu8RH/ksSdY3C1OHaE/8YJz1TPL/dgSbzQpphnX+zwcwsCs/RAn5w==" Feb 12 07:48:35 volumio go-librespot[5416]: time="2026-02-12T07:48:35+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 07:48:35 volumio go-librespot[5416]: time="2026-02-12T07:48:35+07:00" level=debug msg="completed keyexchange" Feb 12 07:48:35 volumio go-librespot[5416]: time="2026-02-12T07:48:35+07:00" level=debug msg="completed challenge" Feb 12 07:48:35 volumio sudo[5440]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-12 07:47' Feb 12 07:48:35 volumio go-librespot[5416]: time="2026-02-12T07:48: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 12 07:48:35 volumio sudo[5440]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 07:48:35 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 07:48:35 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 07:48:36 volumio sudo[5440]: pam_unix(sudo:session): session closed for user root Feb 12 07:48:36 volumio volumio-remote-updater[643]: [2026-02-12 07:48:36] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 12 07:48:36 volumio volumio-remote-updater[643]: [2026-02-12 07:48:36] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 12 07:48:36 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 12 07:48:36 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 12 07:48:36 volumio systemd[1]: volumio.service: Consumed 49.217s CPU time. Feb 12 07:48:36 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 12 07:48:36 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 12 07:48:36 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 12862. Feb 12 07:48:36 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 12 07:48:36 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 12 07:48:36 volumio systemd[1]: volumio.service: Consumed 49.217s CPU time. Feb 12 07:48:36 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 12 07:48:36 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 12 07:48:39 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 28. Feb 12 07:48:39 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 07:48:39 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 07:48:39 volumio go-librespot[5467]: go-librespot daemon starting... Feb 12 07:48:39 volumio go-librespot[5468]: time="2026-02-12T07:48:39+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 07:48:39 volumio go-librespot[5468]: time="2026-02-12T07:48:39+07:00" level=debug msg="app state loaded" Feb 12 07:48:39 volumio go-librespot[5468]: time="2026-02-12T07:48:39+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 07:48:39 volumio go-librespot[5468]: time="2026-02-12T07:48: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 07:48:39 volumio go-librespot[5468]: time="2026-02-12T07:48:39+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 12 07:48:39 volumio go-librespot[5468]: time="2026-02-12T07:48:39+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 12 07:48:39 volumio go-librespot[5468]: time="2026-02-12T07:48:39+07:00" level=info msg="zeroconf server listening on port 39617" Feb 12 07:48:39 volumio go-librespot[5468]: time="2026-02-12T07:48:39+07:00" level=debug msg="obtained new client token: AACPWSEYgd4sCWprfWIdu+7B/VJQuQbcno+LeNVpJC0S2Ymt54HZLrEImC4XvBoQoPljmC06a80FhD0OvK9WLLOGqG4JYojDVtY3BnYIXsGLrZJ4pxQ2BTcCX6xewUR8GoEkeq8fqKvCrGzyybUXrtjUKez6FhAUj8rRp+B3lq9DpM3VQBrCdw/6f1TpxMQmzLbl+NQ+rDiwiBJ3lIxtW65rQqDVR9G5vbFKZqicfIXLpCsoXz/5FSJd5g==" Feb 12 07:48:40 volumio go-librespot[5468]: time="2026-02-12T07:48:40+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 07:48:40 volumio volumio[5452]: info: ------------------------------------------- Feb 12 07:48:40 volumio volumio[5452]: info: ----- Volumio3 ---- Feb 12 07:48:40 volumio volumio[5452]: info: ------------------------------------------- Feb 12 07:48:40 volumio volumio[5452]: info: ----- System startup ---- Feb 12 07:48:40 volumio volumio[5452]: info: ------------------------------------------- Feb 12 07:48:40 volumio go-librespot[5468]: time="2026-02-12T07:48:40+07:00" level=debug msg="completed keyexchange" Feb 12 07:48:40 volumio go-librespot[5468]: time="2026-02-12T07:48:40+07:00" level=debug msg="completed challenge" Feb 12 07:48:40 volumio go-librespot[5468]: time="2026-02-12T07:48:40+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 12 07:48:40 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 07:48:40 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 07:48:41 volumio volumio-remote-updater[643]: [2026-02-12 07:48:41] [connect] Successful connection Feb 12 07:48:41 volumio volumio[5452]: info: MYVOLUMIO Environment detected Feb 12 07:48:41 volumio volumio[5452]: info: Plugin folders cleanup Feb 12 07:48:41 volumio volumio[5452]: info: Scanning into folder /volumio/app/plugins/ Feb 12 07:48:41 volumio volumio[5452]: info: Scanning category audio_interface Feb 12 07:48:41 volumio volumio[5452]: info: Scanning category miscellanea Feb 12 07:48:41 volumio volumio[5452]: info: Scanning category music_service Feb 12 07:48:41 volumio volumio[5452]: info: Scanning category plugins.json Feb 12 07:48:41 volumio volumio[5452]: info: Scanning category system_controller Feb 12 07:48:41 volumio volumio[5452]: info: Scanning category user_interface Feb 12 07:48:41 volumio volumio[5452]: info: Scanning into folder /data/plugins/ Feb 12 07:48:41 volumio volumio[5452]: info: Scanning category music_service Feb 12 07:48:41 volumio volumio[5452]: info: Plugin folders cleanup completed Feb 12 07:48:41 volumio volumio[5452]: info: ------------------------------------------- Feb 12 07:48:41 volumio volumio[5452]: info: ----- Core plugins startup ---- Feb 12 07:48:41 volumio volumio[5452]: info: ------------------------------------------- Feb 12 07:48:41 volumio volumio[5452]: info: Loading plugins from folder /volumio/app/plugins/ Feb 12 07:48:41 volumio volumio[5452]: info: Adding plugin upnp to MyMusic Plugins Feb 12 07:48:41 volumio volumio[5452]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 12 07:48:41 volumio volumio[5452]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 12 07:48:41 volumio volumio[5452]: info: Loading plugins from folder /data/plugins/ Feb 12 07:48:41 volumio volumio[5452]: info: Loading plugin "system"... Feb 12 07:48:41 volumio volumio[5452]: info: Loading plugin "appearance"... Feb 12 07:48:43 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 29. Feb 12 07:48:43 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 07:48:43 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 07:48:43 volumio go-librespot[5489]: go-librespot daemon starting... Feb 12 07:48:43 volumio go-librespot[5490]: time="2026-02-12T07:48:43+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 07:48:43 volumio go-librespot[5490]: time="2026-02-12T07:48:43+07:00" level=debug msg="app state loaded" Feb 12 07:48:43 volumio go-librespot[5490]: time="2026-02-12T07:48:43+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 07:48:43 volumio volumio[5452]: info: Loading plugin "network"... Feb 12 07:48:43 volumio volumio[5452]: info: Refreshing Cached IP Addresses Feb 12 07:48:43 volumio sudo[5499]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 12 07:48:43 volumio sudo[5499]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 07:48:43 volumio sudo[5499]: pam_unix(sudo:session): session closed for user root Feb 12 07:48:43 volumio volumio[5452]: info: Loading plugin "services"... Feb 12 07:48:43 volumio sudo[5501]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 12 07:48:43 volumio sudo[5501]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 07:48:43 volumio volumio[5452]: info: Loading plugin "alsa_controller"... Feb 12 07:48:43 volumio sudo[5501]: pam_unix(sudo:session): session closed for user root Feb 12 07:48:43 volumio sudo[5510]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 12 07:48:43 volumio sudo[5510]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 07:48:43 volumio volumio[5452]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 12 07:48:43 volumio volumio[5452]: info: Loading plugin "wizard"... Feb 12 07:48:43 volumio go-librespot[5490]: time="2026-02-12T07:48:43+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 07:48:43 volumio go-librespot[5490]: time="2026-02-12T07:48:43+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 12 07:48:43 volumio go-librespot[5490]: time="2026-02-12T07:48:43+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 12 07:48:43 volumio volumio[5452]: info: Loading plugin "networkfs"... Feb 12 07:48:43 volumio go-librespot[5490]: time="2026-02-12T07:48:43+07:00" level=info msg="zeroconf server listening on port 36819" Feb 12 07:48:44 volumio volumio[5452]: info: Starting Udev Watcher for removable devices Feb 12 07:48:44 volumio volumio[5452]: info: Ignoring mount for partition: boot Feb 12 07:48:44 volumio volumio[5452]: info: Ignoring mount for partition: volumio Feb 12 07:48:44 volumio volumio[5452]: info: Ignoring mount for partition: volumio_data Feb 12 07:48:44 volumio volumio[5452]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 12 07:48:44 volumio volumio[5452]: info: Loading plugin "volumio_command_line_client"... Feb 12 07:48:44 volumio volumio[5452]: info: Loading plugin "upnp"... Feb 12 07:48:44 volumio volumio[5452]: info: [1770857324131] Starting Upmpd Daemon Feb 12 07:48:44 volumio volumio[5452]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 12 07:48:44 volumio volumio[5452]: info: Loading plugin "my_music"... Feb 12 07:48:44 volumio volumio[5452]: info: Loading plugin "mpd"... Feb 12 07:48:44 volumio go-librespot[5490]: time="2026-02-12T07:48:44+07:00" level=debug msg="obtained new client token: AACGbHhgFVgVc2r/ngPHH+COa6CdTR+PJ4OJTombLYDis7A+D8UsAbylKIO443U++C5ktKLkM7b6Bp0ga0HVOWYtNcLjBc52HYrB9P0IzGLSr4ezZ6cre8ejARhJ6fmCp4eW/xQxO8l/DfwZxsVv3lpb5ZOnlqneuPZygQW7GlL3MzeysfgPxkDnnNeWqBkTxcUyUMvOQioZ8+HCQM9BSitn8+LYpVQMGTqGhVGWd+64yJSeWXvx4uI=" Feb 12 07:48:44 volumio go-librespot[5490]: time="2026-02-12T07:48:44+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 07:48:44 volumio go-librespot[5490]: time="2026-02-12T07:48:44+07:00" level=debug msg="completed keyexchange" Feb 12 07:48:44 volumio go-librespot[5490]: time="2026-02-12T07:48:44+07:00" level=debug msg="completed challenge" Feb 12 07:48:44 volumio go-librespot[5490]: time="2026-02-12T07:48:44+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 12 07:48:44 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 07:48:44 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 07:48:44 volumio volumio[5452]: info: Loading plugin "upnp_browser"... Feb 12 07:48:46 volumio sudo[5510]: pam_unix(sudo:session): session closed for user root Feb 12 07:48:47 volumio volumio[5452]: info: Starting UPNP Browser Feb 12 07:48:47 volumio volumio[5452]: info: Loading plugin "alarm-clock"... Feb 12 07:48:47 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 30. Feb 12 07:48:47 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 07:48:47 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 07:48:47 volumio go-librespot[5532]: go-librespot daemon starting... Feb 12 07:48:47 volumio go-librespot[5533]: time="2026-02-12T07:48:47+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 07:48:47 volumio go-librespot[5533]: time="2026-02-12T07:48:47+07:00" level=debug msg="app state loaded" Feb 12 07:48:47 volumio go-librespot[5533]: time="2026-02-12T07:48:47+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 07:48:48 volumio volumio[5452]: info: Loading plugin "airplay_emulation"... Feb 12 07:48:48 volumio volumio[5452]: info: Starting Shairport Sync Feb 12 07:48:48 volumio volumio[5452]: info: Loading plugin "last_100"... Feb 12 07:48:48 volumio volumio[5452]: info: Loading plugin "webradio"... Feb 12 07:48:48 volumio volumio[5452]: info: Loading plugin "i2s_dacs"... Feb 12 07:48:48 volumio volumio[5452]: info: Loading plugin "volumiodiscovery"... Feb 12 07:48:48 volumio volumio[5452]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 12 07:48:48 volumio volumio[5452]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 12 07:48:48 volumio volumio[5452]: *** WARNING *** For more information see Feb 12 07:48:48 volumio volumio[5452]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 12 07:48:48 volumio volumio[5452]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 12 07:48:48 volumio volumio[5452]: *** WARNING *** For more information see Feb 12 07:48:48 volumio node[5452]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 12 07:48:48 volumio node[5452]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 12 07:48:48 volumio node[5452]: *** WARNING *** For more information see Feb 12 07:48:48 volumio node[5452]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 12 07:48:48 volumio node[5452]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 12 07:48:48 volumio node[5452]: *** WARNING *** For more information see Feb 12 07:48:48 volumio volumio[5452]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 12 07:48:48 volumio volumio[5452]: info: Discovery: Started advertising with name: Volumio Feb 12 07:48:48 volumio go-librespot[5533]: time="2026-02-12T07:48:48+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 12 07:48:48 volumio go-librespot[5533]: time="2026-02-12T07:48:48+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 12 07:48:48 volumio go-librespot[5533]: time="2026-02-12T07:48:48+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 12 07:48:48 volumio volumio[5452]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 12 07:48:48 volumio volumio[5452]: info: Loading plugin "spop"... Feb 12 07:48:48 volumio go-librespot[5533]: time="2026-02-12T07:48:48+07:00" level=info msg="zeroconf server listening on port 34393" Feb 12 07:48:48 volumio go-librespot[5533]: time="2026-02-12T07:48:48+07:00" level=debug msg="obtained new client token: AAC/iiDDxdMWqpUWdeYSrejO2gXNreKHpwbvbSKKaAltNLxbylF1Rp8RdqHMms8bg7ayY6wC28GjeIzjkzFHqdjm3M5k4jjLZIMJuX8mUOHr4Ld2pE4pArnyjEEQi93DIUzW/ulSxYeSGJOwczXTyiXAj2j1nFdSBbqLxnrM+rs+sdzvNywoScDub7B5Ubwh0AhL4gAJuG/bIvhFkva7fUgmIr6e6H7lzHIYLjQWQWoD4vA1pOAqK1gsKQ==" Feb 12 07:48:48 volumio go-librespot[5533]: time="2026-02-12T07:48:48+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 07:48:48 volumio go-librespot[5533]: time="2026-02-12T07:48:48+07:00" level=debug msg="completed keyexchange" Feb 12 07:48:48 volumio go-librespot[5533]: time="2026-02-12T07:48:48+07:00" level=debug msg="completed challenge" Feb 12 07:48:49 volumio go-librespot[5533]: time="2026-02-12T07:48:49+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 12 07:48:49 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 07:48:49 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 07:48:50 volumio volumio[5452]: info: Loading plugin "ytcr"... Feb 12 07:48:52 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 31. Feb 12 07:48:52 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 07:48:52 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 07:48:52 volumio go-librespot[5543]: go-librespot daemon starting... Feb 12 07:48:52 volumio go-librespot[5544]: time="2026-02-12T07:48:52+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 07:48:52 volumio go-librespot[5544]: time="2026-02-12T07:48:52+07:00" level=debug msg="app state loaded" Feb 12 07:48:52 volumio go-librespot[5544]: time="2026-02-12T07:48:52+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 07:48:52 volumio go-librespot[5544]: time="2026-02-12T07:48:52+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 07:48:52 volumio go-librespot[5544]: time="2026-02-12T07:48:52+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 12 07:48:52 volumio go-librespot[5544]: time="2026-02-12T07:48:52+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 12 07:48:52 volumio go-librespot[5544]: time="2026-02-12T07:48:52+07:00" level=info msg="zeroconf server listening on port 40975" Feb 12 07:48:52 volumio volumio[5452]: info: Loading plugin "ytmusic"... Feb 12 07:48:53 volumio go-librespot[5544]: time="2026-02-12T07:48:53+07:00" level=debug msg="obtained new client token: AACwcyOrnw5I4CVUj9tnkA6eDrUw0T6ADTUBogo96cRHX9sM4VMI21zCc/LxBA5mMOTTEKsQ/13EtnkUZO8OFQBKM+zKF304MMaV9hL6/XwXbUM9WvWlJWVCrGdoXE6wbtkDlQ1k06gfBleSWippgBS2AUE3w3OXrn4/fRMtkblTgiTUC91YIhrb7iG4lTJ6yeo3I0RUDgHIjnbOB/0puhdOdW6x2mkNXWlU9zO5D73+c/miPN8Yxno=" Feb 12 07:48:53 volumio go-librespot[5544]: time="2026-02-12T07:48:53+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 07:48:53 volumio go-librespot[5544]: time="2026-02-12T07:48:53+07:00" level=debug msg="completed keyexchange" Feb 12 07:48:53 volumio go-librespot[5544]: time="2026-02-12T07:48:53+07:00" level=debug msg="completed challenge" Feb 12 07:48:53 volumio go-librespot[5544]: time="2026-02-12T07:48:53+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 12 07:48:53 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 07:48:53 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 07:48:53 volumio volumio-remote-updater[643]: [2026-02-12 07:48:53] [connect] Successful connection Feb 12 07:48:54 volumio volumio[5452]: info: Loading plugin "outputs"... Feb 12 07:48:54 volumio volumio[5452]: info: Loading plugin "albumart"... Feb 12 07:48:54 volumio volumio[5452]: info: Plugin example_plugin is not enabled Feb 12 07:48:54 volumio volumio[5452]: info: Loading plugin "inputs"... Feb 12 07:48:54 volumio volumio[5452]: info: Loading plugin "updater_comm"... Feb 12 07:48:54 volumio volumio[5452]: info: Plugin mpdemulation is not enabled Feb 12 07:48:54 volumio volumio[5452]: info: Loading plugin "rest_api"... Feb 12 07:48:54 volumio volumio[5452]: info: Loading plugin "websocket"... Feb 12 07:48:54 volumio volumio[5452]: info: Starting Socket.io Server version 1.7.4 Feb 12 07:48:54 volumio volumio[5452]: info: Loading plugin "RoonBridge"... Feb 12 07:48:54 volumio volumio[5452]: info: Applying required configuration parameters for plugin RoonBridge Feb 12 07:48:54 volumio volumio[5452]: info: Loading i18n strings for locale en Feb 12 07:48:54 volumio volumio[5452]: Updating browse sources language Feb 12 07:48:54 volumio volumio[5452]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 07:48:55 volumio volumio[5452]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 12 07:48:55 volumio volumio[5452]: info: CoreCommandRouter::initPlayerControls Feb 12 07:48:55 volumio volumio[5452]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 07:48:55 volumio volumio[5452]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 07:48:55 volumio volumio[5452]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 07:48:55 volumio volumio[5452]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 07:48:55 volumio volumio[5452]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 07:48:55 volumio volumio[5452]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 07:48:55 volumio volumio[5452]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 07:48:55 volumio volumio[5452]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 07:48:55 volumio volumio[5452]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 12 07:48:55 volumio volumio[5452]: Express server listening on port 3000 Feb 12 07:48:55 volumio volumio[5452]: [Metrics] WebUI: 16s 114.02ms Feb 12 07:48:55 volumio volumio[5565]: Forking 3 albumart workers Feb 12 07:48:55 volumio volumio[5452]: info: CoreStateMachine::resetVolumioState Feb 12 07:48:55 volumio volumio[5452]: info: CoreStateMachine::getcurrentVolume Feb 12 07:48:55 volumio volumio[5452]: info: CoreCommandRouter::volumioRetrievevolume Feb 12 07:48:55 volumio sudo[5599]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 12 07:48:55 volumio sudo[5599]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 07:48:55 volumio sudo[5599]: pam_unix(sudo:session): session closed for user root Feb 12 07:48:55 volumio volumio[5452]: info: Volumio Network Manager: Network status updated: 1 Feb 12 07:48:55 volumio sudo[5603]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 12 07:48:55 volumio sudo[5603]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 07:48:55 volumio sudo[5603]: pam_unix(sudo:session): session closed for user root Feb 12 07:48:55 volumio volumio[5452]: info: VolumeController:: Volume=100 Mute =false Feb 12 07:48:55 volumio volumio[5452]: info: CoreStateMachine::pushState Feb 12 07:48:55 volumio volumio[5452]: info: CorePlayQueue::getTrack 0 Feb 12 07:48:55 volumio volumio[5452]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 12 07:48:55 volumio volumio[5452]: info: CoreCommandRouter::volumioPushState Feb 12 07:48:55 volumio volumio[5452]: info: CoreStateMachine::updateTrackBlock Feb 12 07:48:55 volumio volumio[5452]: info: CorePlayQueue::getTrackBlock Feb 12 07:48:55 volumio volumio[5452]: info: CoreCommandRouter::volumioRetrievevolume Feb 12 07:48:55 volumio volumio-remote-updater[643]: [2026-02-12 07:48:55] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1770857333 101 Feb 12 07:48:55 volumio volumio[5452]: 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 12 07:48:55 volumio volumio[5452]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 07:48:55 volumio volumio[5452]: info: Reloading queue from file Feb 12 07:48:56 volumio volumio[5452]: info: CoreStateMachine::setRepeat null single undefined Feb 12 07:48:56 volumio volumio[5452]: info: CoreStateMachine::pushState Feb 12 07:48:56 volumio volumio[5452]: info: CorePlayQueue::getTrack 0 Feb 12 07:48:56 volumio volumio[5452]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 12 07:48:56 volumio volumio[5452]: info: CoreCommandRouter::volumioPushState Feb 12 07:48:56 volumio volumio[5452]: info: CoreStateMachine::setRandom null Feb 12 07:48:56 volumio volumio[5452]: info: CoreStateMachine::pushState Feb 12 07:48:56 volumio volumio[5452]: info: CorePlayQueue::getTrack 0 Feb 12 07:48:56 volumio volumio[5452]: info: CoreCommandRouter::volumioPushState Feb 12 07:48:56 volumio volumio[5452]: info: Setting Device type: Raspberry PI Feb 12 07:48:56 volumio volumio[5452]: info: Completed loading Core Plugins Feb 12 07:48:56 volumio volumio[5452]: info: Preparing to generate the ALSA configuration file Feb 12 07:48:56 volumio volumio[5452]: info: VolumeController:: Volume=100 Mute =false Feb 12 07:48:56 volumio volumio[5452]: info: CoreStateMachine::pushState Feb 12 07:48:56 volumio volumio[5452]: info: CorePlayQueue::getTrack 0 Feb 12 07:48:56 volumio volumio[5452]: info: CoreCommandRouter::volumioPushState Feb 12 07:48:56 volumio volumio[5452]: info: Asound.conf file unchanged, so no further update is needed Feb 12 07:48:56 volumio volumio[5452]: info: Output device has changed, restarting MPD Feb 12 07:48:56 volumio volumio[5452]: info: Output device has changed, restarting Shairport Sync Feb 12 07:48:56 volumio volumio[5452]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 07:48:56 volumio volumio[5452]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 07:48:56 volumio sudo[5626]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 12 07:48:56 volumio sudo[5630]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 12 07:48:56 volumio sudo[5626]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 07:48:56 volumio sudo[5630]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 07:48:56 volumio sudo[5628]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 12 07:48:56 volumio sudo[5628]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 07:48:56 volumio sudo[5628]: pam_unix(sudo:session): session closed for user root Feb 12 07:48:56 volumio volumio[5452]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 12 07:48:56 volumio volumio[5452]: info: ___________ START PLUGINS ___________ Feb 12 07:48:56 volumio volumio[5452]: info: ControllerMpd::onStart: Initializing MPD Feb 12 07:48:56 volumio volumio[5452]: info: Creating MPD Configuration file Feb 12 07:48:56 volumio volumio[5452]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 12 07:48:56 volumio volumio[5452]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 12 07:48:56 volumio volumio[5452]: info: [1770857336495] CoreMusicLibrary::Adding element Media Servers Feb 12 07:48:56 volumio volumio[5452]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 07:48:56 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 32. Feb 12 07:48:56 volumio volumio[5452]: info: UPNP Browser: Client initialized successfully Feb 12 07:48:56 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 07:48:56 volumio volumio[5452]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 07:48:56 volumio volumio[5452]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 07:48:56 volumio sudo[5639]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 12 07:48:56 volumio sudo[5641]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 12 07:48:56 volumio sudo[5641]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 07:48:56 volumio sudo[5639]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 07:48:56 volumio sudo[5639]: pam_unix(sudo:session): session closed for user root Feb 12 07:48:56 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 07:48:56 volumio go-librespot[5642]: go-librespot daemon starting... Feb 12 07:48:56 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 12 07:48:56 volumio volumio[5452]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 12 07:48:56 volumio volumio[5452]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 07:48:56 volumio volumio[5452]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 07:48:56 volumio go-librespot[5649]: time="2026-02-12T07:48:56+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 07:48:56 volumio go-librespot[5649]: time="2026-02-12T07:48:56+07:00" level=debug msg="app state loaded" Feb 12 07:48:56 volumio sudo[5626]: pam_unix(sudo:session): session closed for user root Feb 12 07:48:56 volumio go-librespot[5649]: time="2026-02-12T07:48:56+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 07:48:56 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 12 07:48:56 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 12 07:48:56 volumio systemd[1]: mpd.service: Consumed 7.086s CPU time. Feb 12 07:48:56 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 12 07:48:56 volumio volumio[5452]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 12 07:48:56 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 12 07:48:56 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 12 07:48:56 volumio volumio[5452]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 12 07:48:56 volumio volumio[5452]: info: [1770857336850] CoreMusicLibrary::Adding element Last_100 Feb 12 07:48:56 volumio volumio[5452]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 07:48:56 volumio volumio[5452]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 12 07:48:56 volumio volumio[5452]: info: [1770857336860] CoreMusicLibrary::Adding element Webradio Feb 12 07:48:56 volumio volumio[5452]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 07:48:56 volumio volumio[5452]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 12 07:48:56 volumio volumio[5452]: info: Initializing BBC Radios Feb 12 07:48:56 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 12 07:48:56 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 12 07:48:56 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 12 07:48:56 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 12 07:48:56 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 12 07:48:57 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 12 07:48:57 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 12 07:48:57 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 12 07:48:57 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 12 07:48:57 volumio volumio[5452]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 12 07:48:57 volumio volumio[5452]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 07:48:57 volumio volumio[5452]: info: Creating Spotify config file Feb 12 07:48:57 volumio volumio[5452]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 07:48:57 volumio go-librespot[5649]: time="2026-02-12T07:48:57+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 07:48:57 volumio go-librespot[5649]: time="2026-02-12T07:48:57+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 12 07:48:57 volumio go-librespot[5649]: time="2026-02-12T07:48:57+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 12 07:48:57 volumio go-librespot[5649]: time="2026-02-12T07:48:57+07:00" level=info msg="zeroconf server listening on port 36379" Feb 12 07:48:57 volumio sudo[5672]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 12 07:48:57 volumio sudo[5672]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 12 07:48:57 volumio sudo[5672]: pam_unix(sudo:session): session closed for user root Feb 12 07:48:57 volumio go-librespot[5649]: time="2026-02-12T07:48:57+07:00" level=debug msg="obtained new client token: AAD4gJMSCNg11AQP4cn6zOFL+9IvraDv5wTz83U88dvSThk2TLc+Vd2FoJlZih7YPtb4kp4V9zcQHyPOKqM2yQ1LZrNMjoEAfxPTZ5YpWSfEyRnZhqedXu5JVW5ioSAlNF9mVh2dquW+iA4FPRWFs/eCKSNA3q7qXtSH58sdJ0R4EVsoube2ri2/JW5RuKGu56xUlTdcEe+psascyb0jb9JBg6R1DIlw4W96Tp4ilP9Hp/hCJs6aVe6ljA==" Feb 12 07:48:57 volumio go-librespot[5649]: time="2026-02-12T07:48:57+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 07:48:58 volumio go-librespot[5649]: time="2026-02-12T07:48:58+07:00" level=debug msg="completed keyexchange" Feb 12 07:48:58 volumio go-librespot[5649]: time="2026-02-12T07:48:58+07:00" level=debug msg="completed challenge" Feb 12 07:48:58 volumio go-librespot[5649]: time="2026-02-12T07:48:58+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 12 07:48:58 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 07:48:58 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 07:48:58 volumio volumio[5452]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 12 07:48:58 volumio volumio[5452]: info: [1770857338563] CoreMusicLibrary::Adding element YouTube Music Feb 12 07:48:58 volumio volumio[5452]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 07:48:58 volumio volumio[5452]: Cannot find translation for source YouTube Music Feb 12 07:48:58 volumio volumio[5452]: info: Volumio Calling Home Feb 12 07:48:58 volumio sudo[5680]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 12 07:48:58 volumio sudo[5680]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 07:48:58 volumio volumio[5578]: Starting albumart workers Feb 12 07:48:58 volumio sudo[5680]: pam_unix(sudo:session): session closed for user root Feb 12 07:48:58 volumio volumio[5579]: Starting albumart workers Feb 12 07:48:59 volumio volumio[5580]: Starting albumart workers Feb 12 07:48:59 volumio volumio[5452]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 12 07:48:59 volumio volumio[5452]: info: Discovery: Found device Volumio Feb 12 07:48:59 volumio volumio[5452]: info: CoreCommandRouter::volumioGetState Feb 12 07:48:59 volumio volumio[5452]: info: CorePlayQueue::getTrack 0 Feb 12 07:48:59 volumio volumio[5452]: info: MPD Permissions set Feb 12 07:48:59 volumio volumio[5452]: info: MPD Permissions set Feb 12 07:48:59 volumio volumio[5452]: info: Upmpdcli Daemon Started Feb 12 07:48:59 volumio volumio[5452]: info: Spotify config file written Feb 12 07:48:59 volumio volumio[5452]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 12 07:48:59 volumio volumio[5452]: info: Discovery: Found device Volumio Feb 12 07:48:59 volumio volumio[5452]: info: CoreCommandRouter::volumioGetState Feb 12 07:48:59 volumio volumio[5452]: info: CorePlayQueue::getTrack 0 Feb 12 07:48:59 volumio sudo[5686]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 12 07:48:59 volumio sudo[5686]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 07:48:59 volumio volumio[5452]: 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 12 07:48:59 volumio volumio[5452]: info: Volumio called home Feb 12 07:48:59 volumio volumio[5452]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 07:48:59 volumio volumio[5452]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 07:48:59 volumio volumio[5452]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 07:48:59 volumio volumio[5452]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 07:48:59 volumio volumio[5452]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 07:48:59 volumio volumio[5452]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 07:48:59 volumio volumio[5452]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 07:48:59 volumio volumio[5452]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 07:48:59 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 07:48:59 volumio volumio[5452]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 07:48:59 volumio volumio[5452]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 07:48:59 volumio volumio[5452]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 07:48:59 volumio volumio[5452]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 07:48:59 volumio volumio[5452]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 07:48:59 volumio volumio[5452]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 07:48:59 volumio volumio[5452]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 07:48:59 volumio go-librespot[5693]: go-librespot daemon starting... Feb 12 07:48:59 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 07:48:59 volumio volumio[5452]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 07:48:59 volumio volumio[5452]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 07:48:59 volumio volumio[5452]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 07:48:59 volumio sudo[5686]: pam_unix(sudo:session): session closed for user root Feb 12 07:48:59 volumio go-librespot[5694]: time="2026-02-12T07:48:59+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 07:48:59 volumio go-librespot[5694]: time="2026-02-12T07:48:59+07:00" level=debug msg="app state loaded" Feb 12 07:48:59 volumio go-librespot[5694]: time="2026-02-12T07:48:59+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 07:48:59 volumio volumio[5452]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 07:48:59 volumio volumio[5452]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 12 07:48:59 volumio volumio[5452]: info: No need to fix Spotify hosts Feb 12 07:49:00 volumio go-librespot[5694]: time="2026-02-12T07:49: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 07:49:00 volumio go-librespot[5694]: time="2026-02-12T07:49:00+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 12 07:49:00 volumio go-librespot[5694]: time="2026-02-12T07:49:00+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 12 07:49:00 volumio go-librespot[5694]: time="2026-02-12T07:49:00+07:00" level=info msg="zeroconf server listening on port 35585" Feb 12 07:49:01 volumio go-librespot[5694]: time="2026-02-12T07:49:01+07:00" level=debug msg="obtained new client token: AACg9vIv3WTGpyMmjrUIfv9qCrkvuLbc/fE8Z6QEG979d0n6M5hsWMxBVNiAE5cDgNnEmSkEVXzDdJzUTmvW6NmwqSgLsNExaoaYja6vHRekJYvlzilLbh6MH+R+KYbuKsMlqVv4huoBCpYLlX8A+O1HGCzlYIDbWiNS8/hbSWaXAH2QclA9dawHx2HrDPFd4Ri6WmYb9cetQM3szGXf/0NT8BYUXdE6dME4hlOs1PeH2sIIhJLBrwYezA==" Feb 12 07:49:01 volumio go-librespot[5694]: time="2026-02-12T07:49:01+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 07:49:01 volumio go-librespot[5694]: time="2026-02-12T07:49:01+07:00" level=debug msg="completed keyexchange" Feb 12 07:49:01 volumio go-librespot[5694]: time="2026-02-12T07:49:01+07:00" level=debug msg="completed challenge" Feb 12 07:49:01 volumio go-librespot[5694]: time="2026-02-12T07:49: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 12 07:49:01 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 07:49:01 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 07:49:01 volumio volumio[5452]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 12 07:49:01 volumio volumio[5452]: SPOTIFY: BQB-uADjgOzHQwit4Co0B_rcysgeAHIF_T5q9TPC7T2fKggqaIqAlqs3Y2a8cZcRxaHGxVP8IonEcVRohaPkrfbWiLy5bxNRL8uWa-aQ9uq6bBYKaFl8xIgqLSg4p4FNX651kjXoohJUQXl4zwF4OBcZXeLpQHTEjfeI8JlcENwDuSAdxwrvDiSsyWq5j9VXz4HFDhUZoI_iH8Kh7NyGo_JGCr50hc4P0Qg-XQpnEN4PbpP3bdt75XhdiAv4IjTEXRwdspBOtJcgKuCD3RMjBjmH2zhCPpVOxdT31ipHsFiBTvt7q7Q0uwd4 Feb 12 07:49:01 volumio volumio[5452]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 12 07:49:01 volumio volumio[5452]: info: New Spotify access token = BQB-uADjgOzHQwit4Co0B_rcysgeAHIF_T5q9TPC7T2fKggqaIqAlqs3Y2a8cZcRxaHGxVP8IonEcVRohaPkrfbWiLy5bxNRL8uWa-aQ9uq6bBYKaFl8xIgqLSg4p4FNX651kjXoohJUQXl4zwF4OBcZXeLpQHTEjfeI8JlcENwDuSAdxwrvDiSsyWq5j9VXz4HFDhUZoI_iH8Kh7NyGo_JGCr50hc4P0Qg-XQpnEN4PbpP3bdt75XhdiAv4IjTEXRwdspBOtJcgKuCD3RMjBjmH2zhCPpVOxdT31ipHsFiBTvt7q7Q0uwd4 Feb 12 07:49:01 volumio volumio[5452]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 12 07:49:01 volumio volumio[5452]: info: Starting Shairport Sync Feb 12 07:49:01 volumio volumio[5452]: info: Starting Shairport Sync Feb 12 07:49:01 volumio volumio[5452]: info: Starting Shairport Sync Feb 12 07:49:01 volumio sudo[5725]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 12 07:49:01 volumio sudo[5725]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 07:49:01 volumio sudo[5729]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 12 07:49:01 volumio sudo[5729]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 07:49:01 volumio sudo[5727]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 12 07:49:01 volumio sudo[5727]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 07:49:01 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 12 07:49:01 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 12 07:49:01 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 12 07:49:01 volumio systemd[1]: shairport-sync.service: Consumed 2.215s CPU time. Feb 12 07:49:01 volumio volumio[5452]: info: CoreCommandRouter::volumioGetState Feb 12 07:49:01 volumio volumio[5452]: info: CorePlayQueue::getTrack 0 Feb 12 07:49:01 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 12 07:49:01 volumio sudo[5725]: pam_unix(sudo:session): session closed for user root Feb 12 07:49:01 volumio sudo[5729]: pam_unix(sudo:session): session closed for user root Feb 12 07:49:02 volumio sudo[5727]: pam_unix(sudo:session): session closed for user root Feb 12 07:49:02 volumio volumio[5452]: info: Shairport-Sync Started Feb 12 07:49:02 volumio volumio[5452]: Error adding Membership: Error: addMembership EINVAL Feb 12 07:49:02 volumio volumio[5452]: info: Shairport-Sync Started Feb 12 07:49:02 volumio volumio[5452]: info: Shairport-Sync Started Feb 12 07:49:02 volumio volumio[5452]: 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 12 07:49:02 volumio volumio[5452]: info: Spotify Successfully logged in Feb 12 07:49:02 volumio volumio[5452]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 12 07:49:02 volumio volumio[5452]: info: [1770857342354] CoreMusicLibrary::Adding element Spotify Feb 12 07:49:02 volumio volumio[5452]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 12 07:49:02 volumio volumio[5452]: Cannot find translation for source YouTube Music Feb 12 07:49:02 volumio volumio[5452]: Cannot find translation for source Spotify Feb 12 07:49:02 volumio volumio[5452]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 12 07:49:02 volumio volumio[5452]: info: CoreCommandRouter::volumioRetrievevolume Feb 12 07:49:03 volumio volumio[5452]: info: VolumeController:: Volume=100 Mute =false Feb 12 07:49:03 volumio volumio[5452]: info: CoreCommandRouter::volumioGetState Feb 12 07:49:03 volumio volumio[5452]: info: CorePlayQueue::getTrack 0 Feb 12 07:49:03 volumio volumio[5452]: info: CoreStateMachine::pushState Feb 12 07:49:03 volumio volumio[5452]: info: CorePlayQueue::getTrack 0 Feb 12 07:49:03 volumio volumio[5452]: info: CoreCommandRouter::volumioPushState Feb 12 07:49:04 volumio volumio[5452]: info: go-librespot daemon successfully initialized Feb 12 07:49:04 volumio mpd[5678]: 2026-02-12T07:49:04 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 12 07:49:04 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 33. Feb 12 07:49:04 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 12 07:49:04 volumio sudo[5641]: pam_unix(sudo:session): session closed for user root Feb 12 07:49:04 volumio sudo[5630]: pam_unix(sudo:session): session closed for user root Feb 12 07:49:04 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 07:49:04 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 07:49:04 volumio go-librespot[5768]: go-librespot daemon starting... Feb 12 07:49:04 volumio go-librespot[5770]: time="2026-02-12T07:49:04+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 07:49:04 volumio go-librespot[5770]: time="2026-02-12T07:49:04+07:00" level=debug msg="app state loaded" Feb 12 07:49:04 volumio go-librespot[5770]: time="2026-02-12T07:49:04+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 07:49:04 volumio volumio[5452]: error: MPD error: The expression evaluated to a falsy value: Feb 12 07:49:04 volumio volumio[5452]: assert.ok(self.idling) Feb 12 07:49:04 volumio volumio[5452]: error: The expression evaluated to a falsy value: Feb 12 07:49:04 volumio volumio[5452]: assert.ok(self.idling) Feb 12 07:49:04 volumio volumio[5452]: info: MPD running with PID5678 Feb 12 07:49:04 volumio volumio[5452]: ,establishing connection Feb 12 07:49:04 volumio volumio[5452]: error: updateQueue error: null Feb 12 07:49:04 volumio volumio[5452]: info: Completed starting Core Plugins Feb 12 07:49:04 volumio volumio[5452]: info: ------------------------------------------- Feb 12 07:49:04 volumio volumio[5452]: info: ----- MyVolumio plugins startup ---- Feb 12 07:49:04 volumio volumio[5452]: info: ------------------------------------------- Feb 12 07:49:04 volumio volumio[5452]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 12 07:49:04 volumio volumio[5452]: error: updateQueue error: null Feb 12 07:49:05 volumio go-librespot[5770]: time="2026-02-12T07:49: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 07:49:05 volumio go-librespot[5770]: time="2026-02-12T07:49:05+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 12 07:49:05 volumio go-librespot[5770]: time="2026-02-12T07:49:05+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 12 07:49:05 volumio go-librespot[5770]: time="2026-02-12T07:49:05+07:00" level=info msg="zeroconf server listening on port 38947" Feb 12 07:49:05 volumio go-librespot[5770]: time="2026-02-12T07:49:05+07:00" level=debug msg="obtained new client token: AAB/YG0YPyeoTkPP2fmN0HLeV7XCv6Mbpt6WOwKWwzWvUz/3xQ/kWqym1kLZkh5Y0bmye/o8muUPBjTAaOkbIxSWCvd7NDBLCp+5+0NSh7ubcEgPLsHHgIoL2te7Qjk6JsOVep4VCdmPjrdQgBx8oe317hPjWek/8AH8Z9fRGDYznmVGHNy+sbN6D2iQs4drdpkVsoLPQARK0A54XhFjVcj/KAf/6LOTi34yloDnCSnzaQ+iIP7vP9wlUA==" Feb 12 07:49:05 volumio go-librespot[5770]: time="2026-02-12T07:49:05+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 07:49:05 volumio go-librespot[5770]: time="2026-02-12T07:49:05+07:00" level=debug msg="completed keyexchange" Feb 12 07:49:05 volumio go-librespot[5770]: time="2026-02-12T07:49:05+07:00" level=debug msg="completed challenge" Feb 12 07:49:05 volumio go-librespot[5770]: time="2026-02-12T07:49:05+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 12 07:49:05 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 07:49:05 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 07:49:07 volumio volumio[5452]: info: Initializing connection to go-librespot Websocket Feb 12 07:49:07 volumio volumio[5452]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 12 07:49:08 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 34. Feb 12 07:49:08 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 07:49:08 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 07:49:08 volumio go-librespot[5777]: go-librespot daemon starting... Feb 12 07:49:08 volumio go-librespot[5778]: time="2026-02-12T07:49:08+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 07:49:08 volumio go-librespot[5778]: time="2026-02-12T07:49:08+07:00" level=debug msg="app state loaded" Feb 12 07:49:08 volumio go-librespot[5778]: time="2026-02-12T07:49:08+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 07:49:09 volumio go-librespot[5778]: time="2026-02-12T07:49:09+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 07:49:09 volumio go-librespot[5778]: time="2026-02-12T07:49:09+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 12 07:49:09 volumio go-librespot[5778]: time="2026-02-12T07:49:09+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 12 07:49:09 volumio go-librespot[5778]: time="2026-02-12T07:49:09+07:00" level=info msg="zeroconf server listening on port 41955" Feb 12 07:49:09 volumio volumio[5452]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 12 07:49:09 volumio go-librespot[5778]: time="2026-02-12T07:49:09+07:00" level=debug msg="obtained new client token: AADr7U+MPxx3EUhDLUUE2McHbB/UZAF22HVquHp3BOky6mWpOWhcCpo/xmkQdAkbl/oJu9fabgD1LSJ0ECYHrtV6T1Avc1wByVbuWX2qF7yj8El0Uk/vPHIc9rcRXY09gNx0AUE0cCGW8w7WkZLLsxNylKR8FPuP+CeS3YTMAciwsNZSCF3pw7wwgbt5vD/YcxZ7uZe3nG2sa53UfXk3l64iGBtK0LsPYNBHeMySImbGwmMfV0NZ4dnEzg==" Feb 12 07:49:09 volumio go-librespot[5778]: time="2026-02-12T07:49:09+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 07:49:09 volumio go-librespot[5778]: time="2026-02-12T07:49:09+07:00" level=debug msg="completed keyexchange" Feb 12 07:49:09 volumio go-librespot[5778]: time="2026-02-12T07:49:09+07:00" level=debug msg="completed challenge" Feb 12 07:49:09 volumio go-librespot[5778]: time="2026-02-12T07:49:09+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 12 07:49:09 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 07:49:09 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 07:49:10 volumio volumio[5452]: info: Initializing connection to go-librespot Websocket Feb 12 07:49:10 volumio volumio[5452]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 12 07:49:13 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 35. Feb 12 07:49:13 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 07:49:13 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 07:49:13 volumio go-librespot[5788]: go-librespot daemon starting... Feb 12 07:49:13 volumio go-librespot[5789]: time="2026-02-12T07:49:13+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 07:49:13 volumio go-librespot[5789]: time="2026-02-12T07:49:13+07:00" level=debug msg="app state loaded" Feb 12 07:49:13 volumio go-librespot[5789]: time="2026-02-12T07:49:13+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 07:49:13 volumio volumio[5452]: info: Initializing connection to go-librespot Websocket Feb 12 07:49:13 volumio go-librespot[5789]: time="2026-02-12T07:49:13+07:00" level=debug msg="new websocket client" Feb 12 07:49:13 volumio volumio[5452]: info: Connection to go-librespot Websocket established Feb 12 07:49:13 volumio volumio[5452]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 12 07:49:13 volumio volumio[5452]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 12 07:49:13 volumio volumio[5452]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 12 07:49:13 volumio volumio[5452]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 12 07:49:13 volumio volumio[5452]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 12 07:49:13 volumio volumio[5452]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 12 07:49:13 volumio volumio[5452]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 12 07:49:13 volumio volumio[5452]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 12 07:49:13 volumio volumio[5452]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 12 07:49:13 volumio volumio[5452]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 12 07:49:13 volumio volumio[5452]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 12 07:49:13 volumio volumio[5452]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 12 07:49:13 volumio volumio[5452]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 12 07:49:13 volumio volumio[5452]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 12 07:49:13 volumio volumio[5452]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 12 07:49:13 volumio volumio[5452]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 12 07:49:13 volumio volumio[5452]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 12 07:49:13 volumio volumio[5452]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 12 07:49:13 volumio volumio[5452]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 12 07:49:13 volumio volumio[5452]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 12 07:49:13 volumio volumio[5452]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 12 07:49:13 volumio volumio[5452]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 12 07:49:13 volumio volumio[5452]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 12 07:49:13 volumio volumio[5452]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 12 07:49:13 volumio volumio[5452]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 12 07:49:13 volumio volumio[5452]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 12 07:49:13 volumio volumio[5452]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 12 07:49:13 volumio volumio[5452]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 12 07:49:13 volumio volumio[5452]: info: Adding plugin bluetooth to MyMusic Plugins Feb 12 07:49:13 volumio volumio[5452]: info: Adding plugin multiroom to MyMusic Plugins Feb 12 07:49:13 volumio volumio[5452]: info: Adding plugin metavolumio to MyMusic Plugins Feb 12 07:49:13 volumio volumio[5452]: info: Adding plugin cd_controller to MyMusic Plugins Feb 12 07:49:13 volumio volumio[5452]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 12 07:49:13 volumio volumio[5452]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 12 07:49:13 volumio volumio[5452]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 12 07:49:13 volumio volumio[5452]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 12 07:49:13 volumio go-librespot[5789]: time="2026-02-12T07:49:13+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 07:49:13 volumio go-librespot[5789]: time="2026-02-12T07:49:13+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 12 07:49:13 volumio go-librespot[5789]: time="2026-02-12T07:49:13+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 12 07:49:13 volumio go-librespot[5789]: time="2026-02-12T07:49:13+07:00" level=info msg="zeroconf server listening on port 37951" Feb 12 07:49:13 volumio go-librespot[5789]: time="2026-02-12T07:49:13+07:00" level=debug msg="obtained new client token: AADDtL+QyDBfnaUb7tZ0XUnrtvt+RHX9LmenK/A7iXPtThBkKny+e3VyHmm13KbEKcZUPFbXx6zNoN0/xV2pz89qMveh0yikCAswnErjBj9jHORYxzcyAezd6NJhqHOFdslFh9qr5Vj902FxFaMFS5yWeUWNzDHvHpy/wU3d/M9Rgxe+2Vv5CqTSlXgELaTFArrgMY5oaL3/eR1fVt2H+07DryMni3N+nXJ6b0RDSf1opHKp/zsVOSe8xg==" Feb 12 07:49:13 volumio go-librespot[5789]: time="2026-02-12T07:49:13+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 12 07:49:14 volumio go-librespot[5789]: time="2026-02-12T07:49:14+07:00" level=debug msg="completed keyexchange" Feb 12 07:49:14 volumio go-librespot[5789]: time="2026-02-12T07:49:14+07:00" level=debug msg="completed challenge" Feb 12 07:49:14 volumio go-librespot[5789]: time="2026-02-12T07:49: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 12 07:49:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 07:49:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 07:49:15 volumio volumio[5452]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 12 07:49:15 volumio volumio[5452]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 12 07:49:15 volumio volumio[5452]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 07:49:15 volumio volumio[5452]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 12 07:49:15 volumio volumio[5452]: info: Starting MyVolumio Remote Streaming Endpoints Feb 12 07:49:15 volumio volumio[5452]: info: MyVolumio login type: Token Feb 12 07:49:15 volumio volumio[5452]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 12 07:49:15 volumio volumio[5452]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 12 07:49:17 volumio volumio[5452]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 12 07:49:17 volumio volumio[5452]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 12 07:49:17 volumio volumio[5452]: info: Streaming services startup Feb 12 07:49:17 volumio volumio[5452]: info: Starting Streaming Daemon Feb 12 07:49:17 volumio sudo[5811]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 12 07:49:17 volumio sudo[5811]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 12 07:49:17 volumio volumio[5452]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 12 07:49:17 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 36. Feb 12 07:49:17 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 12 07:49:17 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 12 07:49:17 volumio go-librespot[5817]: go-librespot daemon starting... Feb 12 07:49:17 volumio sudo[5811]: pam_unix(sudo:session): session closed for user root Feb 12 07:49:17 volumio go-librespot[5818]: time="2026-02-12T07:49:17+07:00" level=info msg="running go-librespot 0.4.0" Feb 12 07:49:17 volumio go-librespot[5818]: time="2026-02-12T07:49:17+07:00" level=debug msg="app state loaded" Feb 12 07:49:17 volumio volumio[5452]: info: Getting Spotify volume Feb 12 07:49:17 volumio go-librespot[5818]: time="2026-02-12T07:49:17+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 12 07:49:17 volumio volumio[5452]: info: Connection to go-librespot Websocket closed Feb 12 07:49:17 volumio volumio[5452]: error: Cannot start Volumio Streaming Daemon Feb 12 07:49:17 volumio volumio[5452]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 12 07:49:17 volumio volumio[5452]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 12 07:49:17 volumio volumio[5452]: 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 12 07:49:17 volumio volumio[5452]: info: CoreCommandRouter::volumioGetState Feb 12 07:49:17 volumio volumio[5452]: info: CorePlayQueue::getTrack 0 Feb 12 07:49:17 volumio volumio[5452]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 12 07:49:17 volumio volumio[5452]: SPOTIFY: SPOTIFY VOLUME undefined Feb 12 07:49:17 volumio volumio[5452]: SPOTIFY: VOLUMIO VOLUME 100 Feb 12 07:49:17 volumio volumio[5452]: info: Aligning Spotify Volume to Volumio Volume Feb 12 07:49:17 volumio volumio[5452]: info: CoreCommandRouter::volumioGetState Feb 12 07:49:17 volumio volumio[5452]: info: CorePlayQueue::getTrack 0 Feb 12 07:49:17 volumio volumio[5452]: info: Setting Spotify Volume from Volumio: 100 Feb 12 07:49:17 volumio go-librespot[5818]: time="2026-02-12T07:49:17+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 12 07:49:17 volumio go-librespot[5818]: time="2026-02-12T07:49:17+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 12 07:49:17 volumio go-librespot[5818]: time="2026-02-12T07:49:17+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 12 07:49:17 volumio go-librespot[5818]: time="2026-02-12T07:49:17+07:00" level=info msg="zeroconf server listening on port 35555" Feb 12 07:49:18 volumio go-librespot[5818]: time="2026-02-12T07:49:18+07:00" level=debug msg="obtained new client token: AADyOwERPHkRPOn7fVrBkIJG4DIz/XWaPF39XyMo9XzcOV2DdKPZqiJe4Mtgp9v20HWhhcRfceEAt4sORXFTvSwptD3jOvZ/ybM/s5xGErzv7eG4EaWNJ8iXPh8cuJoCHrEpS6ea3LXtk5uM7/wHD9bY7vJDUPGCgB9IAuNKu/4NsToFgrA4K1Qt5P1e9h8lLV090u865S7JWzeIpVEbAaa/9r28SFrFj2WSlXO9O4hnbh15aq6kn1Q=" Feb 12 07:49:18 volumio go-librespot[5818]: time="2026-02-12T07:49:18+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 12 07:49:18 volumio go-librespot[5818]: time="2026-02-12T07:49:18+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 12 07:49:18 volumio volumio[5452]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Feb 12 07:49:18 volumio go-librespot[5818]: time="2026-02-12T07:49:18+07:00" level=debug msg="completed keyexchange" Feb 12 07:49:18 volumio go-librespot[5818]: time="2026-02-12T07:49:18+07:00" level=debug msg="completed challenge" Feb 12 07:49:18 volumio go-librespot[5818]: time="2026-02-12T07:49: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 12 07:49:18 volumio volumio[5452]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 12 07:49:18 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 12 07:49:18 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 12 07:49:18 volumio volumio[5452]: Error: socket hang up Feb 12 07:49:18 volumio volumio[5452]: at connResetException (node:internal/errors:720:14) Feb 12 07:49:18 volumio volumio[5452]: at Socket.socketOnEnd (node:_http_client:519:23) Feb 12 07:49:18 volumio volumio[5452]: at Socket.emit (node:events:526:35) Feb 12 07:49:18 volumio volumio[5452]: at endReadableNT (node:internal/streams/readable:1376:12) Feb 12 07:49:18 volumio volumio[5452]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Feb 12 07:49:18 volumio volumio[5452]: code: 'ECONNRESET', Feb 12 07:49:18 volumio volumio[5452]: response: undefined Feb 12 07:49:18 volumio volumio[5452]: } Feb 12 07:49:18 volumio volumio[5452]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 12 07:49:20 volumio sudo[5840]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-12 07:48' Feb 12 07:49:20 volumio sudo[5840]: 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"