Feb 23 23:16:00 volumio go-librespot[21334]: time="2026-02-23T23:16: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 23 23:16:00 volumio go-librespot[21334]: time="2026-02-23T23:16: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 23 23:16:00 volumio go-librespot[21334]: time="2026-02-23T23:16: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 23 23:16:00 volumio go-librespot[21334]: time="2026-02-23T23:16:00+07:00" level=info msg="zeroconf server listening on port 35567" Feb 23 23:16:00 volumio go-librespot[21334]: time="2026-02-23T23:16:00+07:00" level=debug msg="obtained new client token: AAAHLqK23d98skOZxg2XU728oNKhqXWGaFZYGL2pO5VrkBso4IZ6llNJTT6Ngyzzh27q4Go+TKj/WbFCB9s3bpePx4iwgnPkropccut2Y4GK6TIJeg9SZ/m72pyqTAIFDDLsOR4ZPPxtN1vmO69CwkdWQ2EZuHgghR6A4LjVLIpQ+hgAuBYAHyx3ZfSxUwZOB2dH/RYXfYQFm2fbbzbjsmiuzkjFMMJHfEA6w+4kMZpEy5sAjfgjocOb6w==" Feb 23 23:16:00 volumio go-librespot[21334]: time="2026-02-23T23:16:00+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 23 23:16:00 volumio go-librespot[21334]: time="2026-02-23T23:16:00+07:00" level=debug msg="completed keyexchange" Feb 23 23:16:00 volumio go-librespot[21334]: time="2026-02-23T23:16:00+07:00" level=debug msg="completed challenge" Feb 23 23:16:00 volumio go-librespot[21334]: time="2026-02-23T23:16: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 23 23:16:00 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 23 23:16:00 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 23 23:16:01 volumio volumio[21008]: info: Initializing connection to go-librespot Websocket Feb 23 23:16:01 volumio volumio[21008]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 23 23:16:02 volumio volumio[21008]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 23 23:16:04 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 23 23:16:04 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 23 23:16:04 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 23 23:16:04 volumio go-librespot[21341]: go-librespot daemon starting... Feb 23 23:16:04 volumio go-librespot[21342]: time="2026-02-23T23:16:04+07:00" level=info msg="running go-librespot 0.4.0" Feb 23 23:16:04 volumio go-librespot[21342]: time="2026-02-23T23:16:04+07:00" level=debug msg="app state loaded" Feb 23 23:16:04 volumio go-librespot[21342]: time="2026-02-23T23:16:04+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 23 23:16:04 volumio volumio[21008]: info: Initializing connection to go-librespot Websocket Feb 23 23:16:04 volumio go-librespot[21342]: time="2026-02-23T23:16:04+07:00" level=debug msg="new websocket client" Feb 23 23:16:04 volumio volumio[21008]: info: Connection to go-librespot Websocket established Feb 23 23:16:04 volumio go-librespot[21342]: time="2026-02-23T23:16: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 23 23:16:04 volumio go-librespot[21342]: time="2026-02-23T23:16:04+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 23 23:16:04 volumio go-librespot[21342]: time="2026-02-23T23:16:04+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 23 23:16:04 volumio go-librespot[21342]: time="2026-02-23T23:16:04+07:00" level=info msg="zeroconf server listening on port 34331" Feb 23 23:16:05 volumio go-librespot[21342]: time="2026-02-23T23:16:05+07:00" level=debug msg="obtained new client token: AAAJgqL8ShIMD2hBox16gr6spiluxy+2ReB/P6L/3NuQlZZTt0F3Lmoyke3ZXDMCG6S0xlmpro4GTbGKYTSCLqSrJaZCWM/yr8Pb7nRwYc1dxv3AQzsNpqKvMH+ydHkBI0KONeLoOEGGW9OG6ZT0v1LF4rJQgravz6uebXVqSe55w9/h1H+YOEIlCmNP7ABF7rPoTfcGyNfsj61CA8vJARQ5D7Rcm1g8+mdPzV90coxdsNdrhrUjaBE=" Feb 23 23:16:05 volumio go-librespot[21342]: time="2026-02-23T23:16:05+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 23 23:16:05 volumio go-librespot[21342]: time="2026-02-23T23:16:05+07:00" level=debug msg="completed keyexchange" Feb 23 23:16:05 volumio go-librespot[21342]: time="2026-02-23T23:16:05+07:00" level=debug msg="completed challenge" Feb 23 23:16:05 volumio go-librespot[21342]: time="2026-02-23T23:16: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 23 23:16:05 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 23 23:16:05 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 23 23:16:05 volumio volumio[21008]: info: Connection to go-librespot Websocket closed Feb 23 23:16:07 volumio volumio[21008]: info: Getting Spotify volume Feb 23 23:16:07 volumio volumio[21008]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 23 23:16:07 volumio volumio[21008]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 23 23:16:07 volumio volumio[21008]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 23 23:16:07 volumio volumio[21008]: errno: -111, Feb 23 23:16:07 volumio volumio[21008]: code: 'ECONNREFUSED', Feb 23 23:16:07 volumio volumio[21008]: syscall: 'connect', Feb 23 23:16:07 volumio volumio[21008]: address: '127.0.0.1', Feb 23 23:16:07 volumio volumio[21008]: port: 9879, Feb 23 23:16:07 volumio volumio[21008]: response: undefined Feb 23 23:16:07 volumio volumio[21008]: } Feb 23 23:16:07 volumio volumio[21008]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 23 23:16:08 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 23 23:16:08 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 23 23:16:08 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 23 23:16:08 volumio go-librespot[21377]: go-librespot daemon starting... Feb 23 23:16:08 volumio go-librespot[21378]: time="2026-02-23T23:16:08+07:00" level=info msg="running go-librespot 0.4.0" Feb 23 23:16:08 volumio go-librespot[21378]: time="2026-02-23T23:16:08+07:00" level=debug msg="app state loaded" Feb 23 23:16:08 volumio go-librespot[21378]: time="2026-02-23T23:16:08+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 23 23:16:09 volumio sudo[21388]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-23 23:15' Feb 23 23:16:09 volumio sudo[21388]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 23:16:09 volumio go-librespot[21378]: time="2026-02-23T23:16: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 23 23:16:09 volumio go-librespot[21378]: time="2026-02-23T23:16:09+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 23 23:16:09 volumio go-librespot[21378]: time="2026-02-23T23:16:09+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 23 23:16:09 volumio go-librespot[21378]: time="2026-02-23T23:16:09+07:00" level=info msg="zeroconf server listening on port 35541" Feb 23 23:16:09 volumio sudo[21388]: pam_unix(sudo:session): session closed for user root Feb 23 23:16:09 volumio volumio-remote-updater[647]: [2026-02-23 23:16:09] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Feb 23 23:16:09 volumio volumio-remote-updater[647]: [2026-02-23 23:16:09] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Feb 23 23:16:09 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 23 23:16:09 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 23 23:16:09 volumio systemd[1]: volumio.service: Consumed 1min 1.459s CPU time. Feb 23 23:16:09 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 23 23:16:09 volumio go-librespot[21378]: time="2026-02-23T23:16:09+07:00" level=debug msg="obtained new client token: AAAW/zsbTZwILxMHhQChzzqJIBia0WdRbcQmaGcND63seg38JaPesN56zm1T+YAgkNVT++RBs9pT/ViGbkFo6yXEyAegFDtU+Z+AKoHghFE4SuKJ+DXMmex2MCfZl+PjtU+WTb7lexRquPeL35ngcm79hzmdPsXywwjiLzREl5pq+FdHUJmWxyn0/N+MgBYL8vKQCjgmnAj5/3/pgWr/I6r6ubVlmdmWUcRg8lFkmMCYBrN5Qkk8QA3apw==" Feb 23 23:16:09 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 5873. Feb 23 23:16:09 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 23 23:16:09 volumio systemd[1]: volumio.service: Consumed 1min 1.459s CPU time. Feb 23 23:16:09 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 23 23:16:10 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 23 23:16:10 volumio go-librespot[21378]: time="2026-02-23T23:16:10+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 23 23:16:10 volumio go-librespot[21378]: time="2026-02-23T23:16:10+07:00" level=debug msg="completed keyexchange" Feb 23 23:16:10 volumio go-librespot[21378]: time="2026-02-23T23:16:10+07:00" level=debug msg="completed challenge" Feb 23 23:16:10 volumio go-librespot[21378]: time="2026-02-23T23:16:10+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 23 23:16:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 23 23:16:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 23 23:16:13 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Feb 23 23:16:13 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 23 23:16:13 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 23 23:16:13 volumio go-librespot[21413]: go-librespot daemon starting... Feb 23 23:16:13 volumio go-librespot[21420]: time="2026-02-23T23:16:13+07:00" level=info msg="running go-librespot 0.4.0" Feb 23 23:16:13 volumio go-librespot[21420]: time="2026-02-23T23:16:13+07:00" level=debug msg="app state loaded" Feb 23 23:16:13 volumio go-librespot[21420]: time="2026-02-23T23:16:13+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 23 23:16:13 volumio volumio[21396]: info: ------------------------------------------- Feb 23 23:16:13 volumio volumio[21396]: info: ----- Volumio3 ---- Feb 23 23:16:13 volumio volumio[21396]: info: ------------------------------------------- Feb 23 23:16:13 volumio volumio[21396]: info: ----- System startup ---- Feb 23 23:16:13 volumio volumio[21396]: info: ------------------------------------------- Feb 23 23:16:14 volumio go-librespot[21420]: time="2026-02-23T23:16:14+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 23 23:16:14 volumio go-librespot[21420]: time="2026-02-23T23:16:14+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 23 23:16:14 volumio go-librespot[21420]: time="2026-02-23T23:16:14+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 23 23:16:14 volumio go-librespot[21420]: time="2026-02-23T23:16:14+07:00" level=info msg="zeroconf server listening on port 45597" Feb 23 23:16:14 volumio go-librespot[21420]: time="2026-02-23T23:16:14+07:00" level=debug msg="obtained new client token: AABgwC2pZMhp/XToIfqFNlk3/jR6hqXp03tR+F5wYZKLTeoCWDzDaHeH9iY1cg1QJdFDvcOqj9GIV/rHYgzKXy3aZPeuxkJ4JOpR6Urbp56yDIwl//9zpCRsXj+yzqzb86XI09Kjr7nn56R6QUXhMGyMdpw8ThsJI624Qz3jIEiTKkV/49kKbP2mfU52ZA9zheWlkE9LypMk/vxWgQZk5TK9WymwbEA9CE14R4wi78XSDjUFLm2C/XbUOw==" Feb 23 23:16:14 volumio go-librespot[21420]: time="2026-02-23T23:16:14+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 23 23:16:14 volumio go-librespot[21420]: time="2026-02-23T23:16:14+07:00" level=debug msg="completed keyexchange" Feb 23 23:16:14 volumio go-librespot[21420]: time="2026-02-23T23:16:14+07:00" level=debug msg="completed challenge" Feb 23 23:16:14 volumio go-librespot[21420]: time="2026-02-23T23:16: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 23 23:16:14 volumio volumio-remote-updater[647]: [2026-02-23 23:16:14] [connect] Successful connection Feb 23 23:16:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 23 23:16:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 23 23:16:15 volumio volumio[21396]: info: MYVOLUMIO Environment detected Feb 23 23:16:15 volumio volumio[21396]: info: Plugin folders cleanup Feb 23 23:16:15 volumio volumio[21396]: info: Scanning into folder /volumio/app/plugins/ Feb 23 23:16:15 volumio volumio[21396]: info: Scanning category audio_interface Feb 23 23:16:15 volumio volumio[21396]: info: Scanning category miscellanea Feb 23 23:16:15 volumio volumio[21396]: info: Scanning category music_service Feb 23 23:16:15 volumio volumio[21396]: info: Scanning category plugins.json Feb 23 23:16:15 volumio volumio[21396]: info: Scanning category system_controller Feb 23 23:16:15 volumio volumio[21396]: info: Scanning category user_interface Feb 23 23:16:15 volumio volumio[21396]: info: Scanning into folder /data/plugins/ Feb 23 23:16:15 volumio volumio[21396]: info: Scanning category music_service Feb 23 23:16:15 volumio volumio[21396]: info: Plugin folders cleanup completed Feb 23 23:16:15 volumio volumio[21396]: info: ------------------------------------------- Feb 23 23:16:15 volumio volumio[21396]: info: ----- Core plugins startup ---- Feb 23 23:16:15 volumio volumio[21396]: info: ------------------------------------------- Feb 23 23:16:15 volumio volumio[21396]: info: Loading plugins from folder /volumio/app/plugins/ Feb 23 23:16:15 volumio volumio[21396]: info: Adding plugin upnp to MyMusic Plugins Feb 23 23:16:15 volumio volumio[21396]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 23 23:16:15 volumio volumio[21396]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 23 23:16:15 volumio volumio[21396]: info: Loading plugins from folder /data/plugins/ Feb 23 23:16:15 volumio volumio[21396]: info: Loading plugin "system"... Feb 23 23:16:15 volumio volumio[21396]: info: Loading plugin "appearance"... Feb 23 23:16:17 volumio volumio[21396]: info: Loading plugin "network"... Feb 23 23:16:17 volumio volumio[21396]: info: Refreshing Cached IP Addresses Feb 23 23:16:17 volumio sudo[21435]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 23 23:16:17 volumio sudo[21435]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 23:16:17 volumio sudo[21437]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 23 23:16:17 volumio sudo[21437]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 23:16:17 volumio sudo[21435]: pam_unix(sudo:session): session closed for user root Feb 23 23:16:17 volumio volumio[21396]: info: Loading plugin "services"... Feb 23 23:16:17 volumio sudo[21437]: pam_unix(sudo:session): session closed for user root Feb 23 23:16:17 volumio volumio[21396]: info: Loading plugin "alsa_controller"... Feb 23 23:16:17 volumio sudo[21445]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 23 23:16:17 volumio sudo[21445]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 23:16:17 volumio volumio[21396]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 23 23:16:17 volumio volumio[21396]: info: Loading plugin "wizard"... Feb 23 23:16:17 volumio volumio[21396]: info: Loading plugin "networkfs"... Feb 23 23:16:17 volumio volumio[21396]: info: Starting Udev Watcher for removable devices Feb 23 23:16:17 volumio volumio[21396]: info: Ignoring mount for partition: boot Feb 23 23:16:17 volumio volumio[21396]: info: Ignoring mount for partition: volumio Feb 23 23:16:17 volumio volumio[21396]: info: Ignoring mount for partition: volumio_data Feb 23 23:16:17 volumio volumio[21396]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 23 23:16:17 volumio volumio[21396]: info: Loading plugin "volumio_command_line_client"... Feb 23 23:16:17 volumio volumio[21396]: info: Loading plugin "upnp"... Feb 23 23:16:17 volumio volumio[21396]: info: [1771863377716] Starting Upmpd Daemon Feb 23 23:16:17 volumio volumio[21396]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 23 23:16:17 volumio volumio[21396]: info: Loading plugin "my_music"... Feb 23 23:16:17 volumio volumio[21396]: info: Loading plugin "mpd"... Feb 23 23:16:17 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Feb 23 23:16:17 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 23 23:16:17 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 23 23:16:17 volumio go-librespot[21468]: go-librespot daemon starting... Feb 23 23:16:17 volumio go-librespot[21469]: time="2026-02-23T23:16:17+07:00" level=info msg="running go-librespot 0.4.0" Feb 23 23:16:17 volumio go-librespot[21469]: time="2026-02-23T23:16:17+07:00" level=debug msg="app state loaded" Feb 23 23:16:17 volumio go-librespot[21469]: time="2026-02-23T23:16:17+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 23 23:16:18 volumio volumio[21396]: info: Loading plugin "upnp_browser"... Feb 23 23:16:18 volumio go-librespot[21469]: time="2026-02-23T23:16:18+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 23 23:16:18 volumio go-librespot[21469]: time="2026-02-23T23:16:18+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 23 23:16:18 volumio go-librespot[21469]: time="2026-02-23T23:16:18+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 23 23:16:18 volumio go-librespot[21469]: time="2026-02-23T23:16:18+07:00" level=info msg="zeroconf server listening on port 46847" Feb 23 23:16:18 volumio go-librespot[21469]: time="2026-02-23T23:16:18+07:00" level=debug msg="obtained new client token: AACfttxJd78vymvwe8eQotCrFeuX/h2u2A7ijTMDPfqrbqvHv7eD3sPbIpQJAjhNyLoBDiXuuHnuqVMd9xeAa72kDMyyfZZ87R4WSOROx2vPFE+PaGpDpFYckhJElfvsDBXMa7WQm2+ZihbCZ5Fx0C57DbkbLEWGFx3pcf61E2gtOS+zoa4796C/poIOEMyYH8Yz7IDT8gPmgJknWeVOSY7HnFep/oIGHdU2eQwJEz7pxw9ZZzPJ84b/wg==" Feb 23 23:16:19 volumio go-librespot[21469]: time="2026-02-23T23:16:19+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 23 23:16:19 volumio go-librespot[21469]: time="2026-02-23T23:16:19+07:00" level=debug msg="completed keyexchange" Feb 23 23:16:19 volumio go-librespot[21469]: time="2026-02-23T23:16:19+07:00" level=debug msg="completed challenge" Feb 23 23:16:19 volumio go-librespot[21469]: time="2026-02-23T23:16:19+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 23 23:16:19 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 23 23:16:19 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 23 23:16:19 volumio sudo[21445]: pam_unix(sudo:session): session closed for user root Feb 23 23:16:21 volumio volumio[21396]: info: Starting UPNP Browser Feb 23 23:16:21 volumio volumio[21396]: info: Loading plugin "alarm-clock"... Feb 23 23:16:21 volumio volumio[21396]: info: Loading plugin "airplay_emulation"... Feb 23 23:16:21 volumio volumio[21396]: info: Starting Shairport Sync Feb 23 23:16:21 volumio volumio[21396]: info: Loading plugin "last_100"... Feb 23 23:16:21 volumio volumio[21396]: info: Loading plugin "webradio"... Feb 23 23:16:21 volumio volumio[21396]: info: Loading plugin "i2s_dacs"... Feb 23 23:16:21 volumio volumio[21396]: info: Loading plugin "volumiodiscovery"... Feb 23 23:16:22 volumio volumio[21396]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 23 23:16:22 volumio volumio[21396]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 23 23:16:22 volumio node[21396]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 23 23:16:22 volumio volumio[21396]: *** WARNING *** For more information see Feb 23 23:16:22 volumio volumio[21396]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 23 23:16:22 volumio volumio[21396]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 23 23:16:22 volumio volumio[21396]: *** WARNING *** For more information see Feb 23 23:16:22 volumio node[21396]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 23 23:16:22 volumio node[21396]: *** WARNING *** For more information see Feb 23 23:16:22 volumio node[21396]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 23 23:16:22 volumio node[21396]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 23 23:16:22 volumio node[21396]: *** WARNING *** For more information see Feb 23 23:16:22 volumio volumio[21396]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 23 23:16:22 volumio volumio[21396]: info: Discovery: Started advertising with name: Volumio Feb 23 23:16:22 volumio volumio[21396]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 23 23:16:22 volumio volumio[21396]: info: Loading plugin "spop"... Feb 23 23:16:22 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Feb 23 23:16:22 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 23 23:16:22 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 23 23:16:22 volumio go-librespot[21478]: go-librespot daemon starting... Feb 23 23:16:22 volumio go-librespot[21479]: time="2026-02-23T23:16:22+07:00" level=info msg="running go-librespot 0.4.0" Feb 23 23:16:22 volumio go-librespot[21479]: time="2026-02-23T23:16:22+07:00" level=debug msg="app state loaded" Feb 23 23:16:22 volumio go-librespot[21479]: time="2026-02-23T23:16:22+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 23 23:16:23 volumio go-librespot[21479]: time="2026-02-23T23:16:23+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 23 23:16:23 volumio go-librespot[21479]: time="2026-02-23T23:16:23+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 23 23:16:23 volumio go-librespot[21479]: time="2026-02-23T23:16:23+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 23 23:16:23 volumio go-librespot[21479]: time="2026-02-23T23:16:23+07:00" level=info msg="zeroconf server listening on port 40983" Feb 23 23:16:23 volumio go-librespot[21479]: time="2026-02-23T23:16:23+07:00" level=debug msg="obtained new client token: AAAQ3sWutSsemflhodrkbumokTg1HlZgxiLaleZiztsCLJqnBUhz1fXH9D0W1i9X0can4UyfT9UgppAtoc6Z+KS11YW1WTV4Jx5BOJPVmteol7Rhmrb7GkExI6SnMNxR45MLQquJjvvI9A4ZKVitN+ukzEiseGotEARDSpCmuLTN8N+Fyq8+LeQv2j1AOEhiJvi7DxX3+yfv56RHnRthVUnEKfoTp2EBfZGZ+Cj1qMVnucFewyVb/kO6KQ==" Feb 23 23:16:23 volumio go-librespot[21479]: time="2026-02-23T23:16:23+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 23 23:16:23 volumio go-librespot[21479]: time="2026-02-23T23:16:23+07:00" level=debug msg="completed keyexchange" Feb 23 23:16:23 volumio go-librespot[21479]: time="2026-02-23T23:16:23+07:00" level=debug msg="completed challenge" Feb 23 23:16:23 volumio go-librespot[21479]: time="2026-02-23T23:16:23+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 23 23:16:23 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 23 23:16:23 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 23 23:16:24 volumio volumio[21396]: info: Loading plugin "ytcr"... Feb 23 23:16:26 volumio volumio[21396]: info: Loading plugin "ytmusic"... Feb 23 23:16:26 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Feb 23 23:16:26 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 23 23:16:26 volumio go-librespot[21488]: go-librespot daemon starting... Feb 23 23:16:26 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 23 23:16:26 volumio go-librespot[21489]: time="2026-02-23T23:16:26+07:00" level=info msg="running go-librespot 0.4.0" Feb 23 23:16:26 volumio go-librespot[21489]: time="2026-02-23T23:16:26+07:00" level=debug msg="app state loaded" Feb 23 23:16:26 volumio go-librespot[21489]: time="2026-02-23T23:16:26+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 23 23:16:27 volumio volumio-remote-updater[647]: [2026-02-23 23:16:27] [connect] Successful connection Feb 23 23:16:27 volumio go-librespot[21489]: time="2026-02-23T23:16:27+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 23 23:16:27 volumio go-librespot[21489]: time="2026-02-23T23:16:27+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 23 23:16:27 volumio go-librespot[21489]: time="2026-02-23T23:16:27+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 23 23:16:27 volumio go-librespot[21489]: time="2026-02-23T23:16:27+07:00" level=info msg="zeroconf server listening on port 45889" Feb 23 23:16:27 volumio go-librespot[21489]: time="2026-02-23T23:16:27+07:00" level=debug msg="obtained new client token: AAA7fCds+VT2WsAtVNmLV8JvZHZGgQ2+1AgvIWbGUGVR8HMD380ytd82OKl72uLtZzWH/ob9bxEr876qxo3JVq9KXfG3Uz2y/kNwXMRaGZDDp6PV4DlCJwEZ6xc8orjiWtrW0a9UpaSUGd4RsnRsAtc+Jw3Fpl0OXYlAfUAdZpOgWCwxvhD25xrY4BQD4tMn0KFrVMJXAOhjjrqrguAYPaW8ENEWl1f+7qoaR+NPrp0IIAQiUSJx3VHl4w==" Feb 23 23:16:27 volumio volumio[21396]: info: Loading plugin "outputs"... Feb 23 23:16:27 volumio volumio[21396]: info: Loading plugin "albumart"... Feb 23 23:16:27 volumio volumio[21396]: info: Plugin example_plugin is not enabled Feb 23 23:16:27 volumio volumio[21396]: info: Loading plugin "inputs"... Feb 23 23:16:27 volumio go-librespot[21489]: time="2026-02-23T23:16:27+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 23 23:16:27 volumio volumio[21396]: info: Loading plugin "updater_comm"... Feb 23 23:16:28 volumio go-librespot[21489]: time="2026-02-23T23:16:28+07:00" level=debug msg="completed keyexchange" Feb 23 23:16:28 volumio go-librespot[21489]: time="2026-02-23T23:16:28+07:00" level=debug msg="completed challenge" Feb 23 23:16:28 volumio volumio[21396]: info: Plugin mpdemulation is not enabled Feb 23 23:16:28 volumio volumio[21396]: info: Loading plugin "rest_api"... Feb 23 23:16:28 volumio volumio[21396]: info: Loading plugin "websocket"... Feb 23 23:16:28 volumio go-librespot[21489]: time="2026-02-23T23:16:28+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 23 23:16:28 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 23 23:16:28 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 23 23:16:28 volumio volumio[21396]: info: Starting Socket.io Server version 1.7.4 Feb 23 23:16:28 volumio volumio[21396]: info: Loading plugin "RoonBridge"... Feb 23 23:16:28 volumio volumio[21396]: info: Applying required configuration parameters for plugin RoonBridge Feb 23 23:16:28 volumio volumio[21396]: info: Loading i18n strings for locale en Feb 23 23:16:28 volumio volumio[21396]: Updating browse sources language Feb 23 23:16:28 volumio volumio[21396]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 23 23:16:29 volumio volumio[21511]: Forking 3 albumart workers Feb 23 23:16:29 volumio volumio[21396]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 23 23:16:29 volumio volumio[21396]: info: CoreCommandRouter::initPlayerControls Feb 23 23:16:29 volumio volumio[21396]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 23:16:29 volumio volumio[21396]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 23:16:29 volumio volumio[21396]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 23:16:29 volumio volumio[21396]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 23:16:29 volumio volumio[21396]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 23:16:29 volumio volumio[21396]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 23:16:29 volumio volumio[21396]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 23:16:29 volumio volumio[21396]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 23:16:29 volumio volumio[21396]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 23 23:16:29 volumio volumio[21396]: Express server listening on port 3000 Feb 23 23:16:29 volumio volumio[21396]: [Metrics] WebUI: 16s 579.52ms Feb 23 23:16:29 volumio volumio[21396]: info: CoreStateMachine::resetVolumioState Feb 23 23:16:29 volumio volumio[21396]: info: CoreStateMachine::getcurrentVolume Feb 23 23:16:29 volumio volumio[21396]: info: CoreCommandRouter::volumioRetrievevolume Feb 23 23:16:29 volumio sudo[21553]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 23 23:16:29 volumio sudo[21553]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 23:16:29 volumio sudo[21555]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 23 23:16:29 volumio sudo[21555]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 23:16:29 volumio sudo[21553]: pam_unix(sudo:session): session closed for user root Feb 23 23:16:29 volumio sudo[21555]: pam_unix(sudo:session): session closed for user root Feb 23 23:16:29 volumio volumio[21396]: info: Volumio Network Manager: Network status updated: 1 Feb 23 23:16:29 volumio volumio-remote-updater[647]: [2026-02-23 23:16:29] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1771863387 101 Feb 23 23:16:30 volumio volumio[21396]: 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 23 23:16:30 volumio volumio[21396]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 23 23:16:30 volumio volumio[21396]: info: Reloading queue from file Feb 23 23:16:30 volumio volumio[21396]: info: VolumeController:: Volume=100 Mute =false Feb 23 23:16:30 volumio volumio[21396]: info: CoreStateMachine::pushState Feb 23 23:16:30 volumio volumio[21396]: info: CorePlayQueue::getTrack 0 Feb 23 23:16:30 volumio volumio[21396]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 23 23:16:30 volumio volumio[21396]: info: CoreCommandRouter::volumioPushState Feb 23 23:16:30 volumio volumio[21396]: info: CoreStateMachine::updateTrackBlock Feb 23 23:16:30 volumio volumio[21396]: info: CorePlayQueue::getTrackBlock Feb 23 23:16:30 volumio volumio[21396]: info: CoreCommandRouter::volumioRetrievevolume Feb 23 23:16:30 volumio volumio[21396]: info: CoreStateMachine::setRepeat null single undefined Feb 23 23:16:30 volumio volumio[21396]: info: CoreStateMachine::pushState Feb 23 23:16:30 volumio volumio[21396]: info: CorePlayQueue::getTrack 0 Feb 23 23:16:30 volumio volumio[21396]: info: CoreCommandRouter::volumioPushState Feb 23 23:16:30 volumio volumio[21396]: info: CoreStateMachine::setRandom null Feb 23 23:16:30 volumio volumio[21396]: info: CoreStateMachine::pushState Feb 23 23:16:30 volumio volumio[21396]: info: CorePlayQueue::getTrack 0 Feb 23 23:16:30 volumio volumio[21396]: info: CoreCommandRouter::volumioPushState Feb 23 23:16:30 volumio volumio[21396]: info: Setting Device type: Raspberry PI Feb 23 23:16:30 volumio volumio[21396]: info: Completed loading Core Plugins Feb 23 23:16:30 volumio volumio[21396]: info: Preparing to generate the ALSA configuration file Feb 23 23:16:30 volumio volumio[21396]: info: VolumeController:: Volume=100 Mute =false Feb 23 23:16:30 volumio volumio[21396]: info: CoreStateMachine::pushState Feb 23 23:16:30 volumio volumio[21396]: info: CorePlayQueue::getTrack 0 Feb 23 23:16:30 volumio volumio[21396]: info: CoreCommandRouter::volumioPushState Feb 23 23:16:30 volumio volumio[21396]: info: Asound.conf file unchanged, so no further update is needed Feb 23 23:16:30 volumio volumio[21396]: info: Output device has changed, restarting MPD Feb 23 23:16:30 volumio sudo[21573]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 23 23:16:30 volumio sudo[21573]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 23:16:30 volumio volumio[21396]: info: Output device has changed, restarting Shairport Sync Feb 23 23:16:30 volumio volumio[21396]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 23:16:30 volumio volumio[21396]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 23 23:16:30 volumio sudo[21576]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 23 23:16:30 volumio sudo[21576]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 23:16:30 volumio sudo[21576]: pam_unix(sudo:session): session closed for user root Feb 23 23:16:30 volumio sudo[21579]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 23 23:16:30 volumio sudo[21579]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 23:16:30 volumio sudo[21573]: pam_unix(sudo:session): session closed for user root Feb 23 23:16:30 volumio volumio[21396]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 23 23:16:30 volumio volumio[21396]: info: ___________ START PLUGINS ___________ Feb 23 23:16:30 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 23 23:16:30 volumio volumio[21396]: info: ControllerMpd::onStart: Initializing MPD Feb 23 23:16:30 volumio volumio[21396]: info: Creating MPD Configuration file Feb 23 23:16:30 volumio volumio[21396]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 23 23:16:30 volumio volumio[21396]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 23 23:16:30 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 23 23:16:30 volumio volumio[21396]: info: [1771863390966] CoreMusicLibrary::Adding element Media Servers Feb 23 23:16:30 volumio volumio[21396]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 23 23:16:30 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 23 23:16:30 volumio systemd[1]: mpd.service: Consumed 6.885s CPU time. Feb 23 23:16:30 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 23 23:16:30 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 23 23:16:30 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 23 23:16:30 volumio sudo[21588]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 23 23:16:31 volumio sudo[21588]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 23:16:31 volumio sudo[21586]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 23 23:16:31 volumio volumio[21396]: info: UPNP Browser: Client initialized successfully Feb 23 23:16:31 volumio sudo[21586]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 23:16:31 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 23 23:16:31 volumio sudo[21586]: pam_unix(sudo:session): session closed for user root Feb 23 23:16:31 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 23 23:16:31 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Feb 23 23:16:31 volumio volumio[21396]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 23:16:31 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 23 23:16:31 volumio volumio[21396]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 23 23:16:31 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 23 23:16:31 volumio go-librespot[21594]: go-librespot daemon starting... Feb 23 23:16:31 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 23 23:16:31 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 23 23:16:31 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 23 23:16:31 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 23 23:16:31 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 23 23:16:31 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 23 23:16:31 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 23 23:16:31 volumio go-librespot[21596]: time="2026-02-23T23:16:31+07:00" level=info msg="running go-librespot 0.4.0" Feb 23 23:16:31 volumio go-librespot[21596]: time="2026-02-23T23:16:31+07:00" level=debug msg="app state loaded" Feb 23 23:16:31 volumio go-librespot[21596]: time="2026-02-23T23:16:31+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 23 23:16:31 volumio volumio[21396]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 23 23:16:31 volumio volumio[21396]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 23:16:31 volumio volumio[21396]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 23 23:16:31 volumio volumio[21396]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 23 23:16:31 volumio volumio[21396]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 23 23:16:31 volumio volumio[21396]: info: [1771863391621] CoreMusicLibrary::Adding element Last_100 Feb 23 23:16:31 volumio volumio[21396]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 23 23:16:31 volumio volumio[21396]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 23 23:16:31 volumio volumio[21396]: info: [1771863391651] CoreMusicLibrary::Adding element Webradio Feb 23 23:16:31 volumio volumio[21396]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 23 23:16:31 volumio volumio[21396]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 23 23:16:31 volumio volumio[21396]: info: Initializing BBC Radios Feb 23 23:16:31 volumio sudo[21605]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 23 23:16:31 volumio sudo[21605]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 23 23:16:31 volumio sudo[21605]: pam_unix(sudo:session): session closed for user root Feb 23 23:16:31 volumio go-librespot[21596]: time="2026-02-23T23:16:31+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 23 23:16:31 volumio go-librespot[21596]: time="2026-02-23T23:16:31+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 23 23:16:31 volumio go-librespot[21596]: time="2026-02-23T23:16:31+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 23 23:16:32 volumio go-librespot[21596]: time="2026-02-23T23:16:32+07:00" level=info msg="zeroconf server listening on port 42437" Feb 23 23:16:32 volumio volumio[21396]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 23 23:16:32 volumio volumio[21396]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 23 23:16:32 volumio volumio[21396]: info: Creating Spotify config file Feb 23 23:16:32 volumio volumio[21396]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 23:16:32 volumio go-librespot[21596]: time="2026-02-23T23:16:32+07:00" level=debug msg="obtained new client token: AADc8RLiYtwyqvcqOlXKBlVaw5fg0wlGnjnmjAPfkhZKugLgRlFA1Cl0GqhtHBvGY3K9L16IK1n9zYjKP3f51QHWnY7vKH9dWjZgmQQ1S7IYMMm8frdl4JUX/zcw79caaReglrxKjiHV+5djj/k+lbl9fHplRrz+dXay5UkhtBK61GceS+yr5ulbAfr0MdVM8y0X9r5f9BOWZdUOAeD6qPQaLT5HXh0vZd7UVDuHlHvXEokppxtd8L4TKg==" Feb 23 23:16:32 volumio go-librespot[21596]: time="2026-02-23T23:16:32+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 23 23:16:32 volumio go-librespot[21596]: time="2026-02-23T23:16:32+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 23 23:16:33 volumio volumio[21523]: Starting albumart workers Feb 23 23:16:33 volumio go-librespot[21596]: time="2026-02-23T23:16:33+07:00" level=debug msg="completed keyexchange" Feb 23 23:16:33 volumio go-librespot[21596]: time="2026-02-23T23:16:33+07:00" level=debug msg="completed challenge" Feb 23 23:16:33 volumio go-librespot[21596]: time="2026-02-23T23:16:33+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 23 23:16:33 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 23 23:16:33 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 23 23:16:33 volumio volumio[21521]: Starting albumart workers Feb 23 23:16:34 volumio volumio[21522]: Starting albumart workers Feb 23 23:16:34 volumio volumio[21396]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 23 23:16:34 volumio volumio[21396]: info: [1771863394033] CoreMusicLibrary::Adding element YouTube Music Feb 23 23:16:34 volumio volumio[21396]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 23 23:16:34 volumio volumio[21396]: Cannot find translation for source YouTube Music Feb 23 23:16:34 volumio volumio[21396]: info: Volumio Calling Home Feb 23 23:16:34 volumio sudo[21628]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 23 23:16:34 volumio sudo[21628]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 23:16:34 volumio sudo[21628]: pam_unix(sudo:session): session closed for user root Feb 23 23:16:35 volumio volumio[21396]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 23 23:16:35 volumio volumio[21396]: info: Discovery: Found device Volumio Feb 23 23:16:35 volumio volumio[21396]: info: CoreCommandRouter::volumioGetState Feb 23 23:16:35 volumio volumio[21396]: info: CorePlayQueue::getTrack 0 Feb 23 23:16:35 volumio volumio[21396]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 23 23:16:35 volumio volumio[21396]: info: Discovery: Found device Volumio Feb 23 23:16:35 volumio volumio[21396]: info: CoreCommandRouter::volumioGetState Feb 23 23:16:35 volumio volumio[21396]: info: CorePlayQueue::getTrack 0 Feb 23 23:16:35 volumio volumio[21396]: info: MPD Permissions set Feb 23 23:16:35 volumio volumio[21396]: info: MPD Permissions set Feb 23 23:16:35 volumio volumio[21396]: info: Upmpdcli Daemon Started Feb 23 23:16:36 volumio volumio[21396]: 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 23 23:16:36 volumio volumio[21396]: info: Volumio called home Feb 23 23:16:36 volumio volumio[21396]: info: Spotify config file written Feb 23 23:16:36 volumio sudo[21646]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 23 23:16:36 volumio sudo[21646]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 23:16:36 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Feb 23 23:16:36 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 23 23:16:36 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 23 23:16:36 volumio go-librespot[21654]: go-librespot daemon starting... Feb 23 23:16:36 volumio sudo[21646]: pam_unix(sudo:session): session closed for user root Feb 23 23:16:36 volumio go-librespot[21655]: time="2026-02-23T23:16:36+07:00" level=info msg="running go-librespot 0.4.0" Feb 23 23:16:36 volumio go-librespot[21655]: time="2026-02-23T23:16:36+07:00" level=debug msg="app state loaded" Feb 23 23:16:36 volumio go-librespot[21655]: time="2026-02-23T23:16:36+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 23 23:16:37 volumio volumio[21396]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 23:16:37 volumio volumio[21396]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 23:16:37 volumio volumio[21396]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 23:16:37 volumio volumio[21396]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 23:16:37 volumio volumio[21396]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 23:16:37 volumio volumio[21396]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 23:16:37 volumio volumio[21396]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 23:16:37 volumio volumio[21396]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 23:16:37 volumio volumio[21396]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 23 23:16:37 volumio volumio[21396]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 23:16:37 volumio volumio[21396]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 23:16:37 volumio volumio[21396]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 23:16:37 volumio volumio[21396]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 23:16:37 volumio volumio[21396]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 23:16:37 volumio volumio[21396]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 23:16:37 volumio volumio[21396]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 23:16:37 volumio volumio[21396]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 23:16:37 volumio volumio[21396]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 23:16:37 volumio volumio[21396]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 23 23:16:37 volumio volumio[21396]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 23:16:37 volumio volumio[21396]: info: No need to fix Spotify hosts Feb 23 23:16:37 volumio go-librespot[21655]: time="2026-02-23T23:16:37+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 23 23:16:37 volumio go-librespot[21655]: time="2026-02-23T23:16:37+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 23 23:16:37 volumio go-librespot[21655]: time="2026-02-23T23:16:37+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 23 23:16:37 volumio go-librespot[21655]: time="2026-02-23T23:16:37+07:00" level=info msg="zeroconf server listening on port 40483" Feb 23 23:16:37 volumio volumio[21396]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 23 23:16:37 volumio volumio[21396]: SPOTIFY: BQDzRLVB8FNsAjbnvASL57jmGDbVpFHpLIcQEYLHJZIRkJqxIAAFaRRbmKTwKIdKbzSZxBDgHuqVyceeYBrBrWthcZYsepLmlnYIDREqBRtQUfPdlluyjX5m-k4nz_CsYG1PjiNUe076u--JD2TfylY4LPWSjQJ0vbSrGgwP0SrJglhZVqcmyZp30DTUINsXJSBZNQEYUdTJ6uIv1nNxJ7hwnKEH8n7ob_8c2t0xfGow2FlgpCDDWzu232cWxm0AzHHUZG0WoGlyGCqdg4ezh9reyN-rQ-iTT70JSyP8jVgCtnBgA9O0qvMw Feb 23 23:16:37 volumio volumio[21396]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 23 23:16:37 volumio volumio[21396]: info: New Spotify access token = BQDzRLVB8FNsAjbnvASL57jmGDbVpFHpLIcQEYLHJZIRkJqxIAAFaRRbmKTwKIdKbzSZxBDgHuqVyceeYBrBrWthcZYsepLmlnYIDREqBRtQUfPdlluyjX5m-k4nz_CsYG1PjiNUe076u--JD2TfylY4LPWSjQJ0vbSrGgwP0SrJglhZVqcmyZp30DTUINsXJSBZNQEYUdTJ6uIv1nNxJ7hwnKEH8n7ob_8c2t0xfGow2FlgpCDDWzu232cWxm0AzHHUZG0WoGlyGCqdg4ezh9reyN-rQ-iTT70JSyP8jVgCtnBgA9O0qvMw Feb 23 23:16:37 volumio volumio[21396]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 23 23:16:37 volumio go-librespot[21655]: time="2026-02-23T23:16:37+07:00" level=debug msg="obtained new client token: AACTH2SwWwXWd4f/EZtpLeVrjwkhlqnu8sEC8gBsC6C8wkYfx+8JkEl1AV0YY87gtS7ViaQNrdEjHVP4e5+EC3SwHbVLKyc7BSMOr4zQ+F86eFWftYuAIwusdlH4l2c78593RQUSx0PLu1LAhdFSam6IRYtztX4SL1zvlPRrJ9R6V/wCLe0858ea6cy9/As/b3+nBShySPFtLPJWzI/yGJQP03VRyjCX5zyU8w7qXyRN1tG9ybBi/U2aMw==" Feb 23 23:16:37 volumio volumio[21396]: info: Starting Shairport Sync Feb 23 23:16:37 volumio go-librespot[21655]: time="2026-02-23T23:16:37+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 23 23:16:37 volumio volumio[21396]: info: Starting Shairport Sync Feb 23 23:16:37 volumio volumio[21396]: info: Starting Shairport Sync Feb 23 23:16:37 volumio go-librespot[21655]: time="2026-02-23T23:16:37+07:00" level=debug msg="completed keyexchange" Feb 23 23:16:37 volumio go-librespot[21655]: time="2026-02-23T23:16:37+07:00" level=debug msg="completed challenge" Feb 23 23:16:37 volumio sudo[21690]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 23 23:16:37 volumio sudo[21688]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 23 23:16:37 volumio sudo[21690]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 23:16:37 volumio sudo[21688]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 23:16:38 volumio go-librespot[21655]: time="2026-02-23T23:16:38+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 23 23:16:38 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 23 23:16:38 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 23 23:16:38 volumio sudo[21692]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 23 23:16:38 volumio sudo[21692]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 23:16:38 volumio volumio[21396]: info: CoreCommandRouter::volumioGetState Feb 23 23:16:38 volumio volumio[21396]: info: CorePlayQueue::getTrack 0 Feb 23 23:16:38 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 23 23:16:38 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 23 23:16:38 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 23 23:16:38 volumio systemd[1]: shairport-sync.service: Consumed 2.169s CPU time. Feb 23 23:16:38 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 23 23:16:38 volumio volumio[21396]: 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 23 23:16:38 volumio sudo[21688]: pam_unix(sudo:session): session closed for user root Feb 23 23:16:38 volumio sudo[21690]: pam_unix(sudo:session): session closed for user root Feb 23 23:16:38 volumio sudo[21692]: pam_unix(sudo:session): session closed for user root Feb 23 23:16:38 volumio volumio[21396]: info: Spotify Successfully logged in Feb 23 23:16:38 volumio volumio[21396]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 23 23:16:38 volumio volumio[21396]: info: [1771863398550] CoreMusicLibrary::Adding element Spotify Feb 23 23:16:38 volumio volumio[21396]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 23 23:16:38 volumio volumio[21396]: Cannot find translation for source YouTube Music Feb 23 23:16:38 volumio volumio[21396]: Cannot find translation for source Spotify Feb 23 23:16:38 volumio volumio[21396]: info: Shairport-Sync Started Feb 23 23:16:38 volumio volumio[21396]: Error adding Membership: Error: addMembership EINVAL Feb 23 23:16:38 volumio volumio[21396]: info: Shairport-Sync Started Feb 23 23:16:38 volumio volumio[21396]: info: Shairport-Sync Started Feb 23 23:16:39 volumio mpd[21616]: 2026-02-23T23:16:39 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 23 23:16:39 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 23 23:16:39 volumio sudo[21588]: pam_unix(sudo:session): session closed for user root Feb 23 23:16:39 volumio sudo[21579]: pam_unix(sudo:session): session closed for user root Feb 23 23:16:39 volumio volumio[21396]: error: MPD error: The expression evaluated to a falsy value: Feb 23 23:16:39 volumio volumio[21396]: assert.ok(self.idling) Feb 23 23:16:39 volumio volumio[21396]: error: The expression evaluated to a falsy value: Feb 23 23:16:39 volumio volumio[21396]: assert.ok(self.idling) Feb 23 23:16:39 volumio volumio[21396]: info: MPD running with PID21616 Feb 23 23:16:39 volumio volumio[21396]: ,establishing connection Feb 23 23:16:39 volumio volumio[21396]: error: updateQueue error: null Feb 23 23:16:39 volumio volumio[21396]: error: updateQueue error: null Feb 23 23:16:39 volumio volumio[21396]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 23 23:16:39 volumio volumio[21396]: info: CoreCommandRouter::volumioRetrievevolume Feb 23 23:16:40 volumio volumio[21396]: info: VolumeController:: Volume=100 Mute =false Feb 23 23:16:40 volumio volumio[21396]: info: CoreCommandRouter::volumioGetState Feb 23 23:16:40 volumio volumio[21396]: info: CorePlayQueue::getTrack 0 Feb 23 23:16:40 volumio volumio[21396]: info: CoreStateMachine::pushState Feb 23 23:16:40 volumio volumio[21396]: info: CorePlayQueue::getTrack 0 Feb 23 23:16:40 volumio volumio[21396]: info: CoreCommandRouter::volumioPushState Feb 23 23:16:40 volumio volumio[21396]: info: Completed starting Core Plugins Feb 23 23:16:40 volumio volumio[21396]: info: ------------------------------------------- Feb 23 23:16:40 volumio volumio[21396]: info: ----- MyVolumio plugins startup ---- Feb 23 23:16:40 volumio volumio[21396]: info: ------------------------------------------- Feb 23 23:16:40 volumio volumio[21396]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 23 23:16:40 volumio volumio[21396]: info: go-librespot daemon successfully initialized Feb 23 23:16:41 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Feb 23 23:16:41 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 23 23:16:41 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 23 23:16:41 volumio go-librespot[21718]: go-librespot daemon starting... Feb 23 23:16:41 volumio go-librespot[21719]: time="2026-02-23T23:16:41+07:00" level=info msg="running go-librespot 0.4.0" Feb 23 23:16:41 volumio go-librespot[21719]: time="2026-02-23T23:16:41+07:00" level=debug msg="app state loaded" Feb 23 23:16:41 volumio go-librespot[21719]: time="2026-02-23T23:16:41+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 23 23:16:41 volumio go-librespot[21719]: time="2026-02-23T23:16:41+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 23 23:16:41 volumio go-librespot[21719]: time="2026-02-23T23:16:41+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 23 23:16:41 volumio go-librespot[21719]: time="2026-02-23T23:16:41+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 23 23:16:41 volumio go-librespot[21719]: time="2026-02-23T23:16:41+07:00" level=info msg="zeroconf server listening on port 41795" Feb 23 23:16:42 volumio go-librespot[21719]: time="2026-02-23T23:16:42+07:00" level=debug msg="obtained new client token: AABa3Ih0SSu670iidPnAjyMLbud24xKnuRNUgfZt9D6Oh7fv7rOzMbxvA5yH9hZuhzVf11zeqSGQKYBXGtV24GCI4i3eU6ftFyVvdy5BAJuVHAOrlUA6mOGymxtyazPY7hwLwRPZGmJbkZCmV3VSlfJp8+eNPAGnfFGd98L9curQwQsQK4I+vmrMpc5fwNGfY6mKyBydxOYqURpBfdqtQAVhUsd6qZyXFR8CGD/UFPyhew6nKl2cC9w=" Feb 23 23:16:42 volumio go-librespot[21719]: time="2026-02-23T23:16:42+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 23 23:16:42 volumio go-librespot[21719]: time="2026-02-23T23:16:42+07:00" level=debug msg="completed keyexchange" Feb 23 23:16:42 volumio go-librespot[21719]: time="2026-02-23T23:16:42+07:00" level=debug msg="completed challenge" Feb 23 23:16:42 volumio go-librespot[21719]: time="2026-02-23T23:16:42+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 23 23:16:42 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 23 23:16:42 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 23 23:16:43 volumio volumio[21396]: info: Initializing connection to go-librespot Websocket Feb 23 23:16:43 volumio volumio[21396]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 23 23:16:44 volumio volumio[21396]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 23 23:16:45 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Feb 23 23:16:45 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 23 23:16:45 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 23 23:16:45 volumio go-librespot[21728]: go-librespot daemon starting... Feb 23 23:16:45 volumio go-librespot[21729]: time="2026-02-23T23:16:45+07:00" level=info msg="running go-librespot 0.4.0" Feb 23 23:16:45 volumio go-librespot[21729]: time="2026-02-23T23:16:45+07:00" level=debug msg="app state loaded" Feb 23 23:16:45 volumio go-librespot[21729]: time="2026-02-23T23:16:45+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 23 23:16:46 volumio go-librespot[21729]: time="2026-02-23T23:16:46+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 23 23:16:46 volumio go-librespot[21729]: time="2026-02-23T23:16:46+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 23 23:16:46 volumio go-librespot[21729]: time="2026-02-23T23:16:46+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 23 23:16:46 volumio go-librespot[21729]: time="2026-02-23T23:16:46+07:00" level=info msg="zeroconf server listening on port 39931" Feb 23 23:16:46 volumio volumio[21396]: info: Initializing connection to go-librespot Websocket Feb 23 23:16:46 volumio go-librespot[21729]: time="2026-02-23T23:16:46+07:00" level=debug msg="new websocket client" Feb 23 23:16:46 volumio volumio[21396]: info: Connection to go-librespot Websocket established Feb 23 23:16:46 volumio go-librespot[21729]: time="2026-02-23T23:16:46+07:00" level=debug msg="obtained new client token: AABzJV1sk8cE/Tdd6ZQq5KXCVq3SNhDtc+Pbp5m0e+2Xs/oxLxX3cEwVmSEU8iXYifmlPZHwoVRLOPmOH9ffI4JOB2OQe89P/b9r7T4/UPYKvBbrGYfWGYwckrzKhvlmsiHHwwYastYyE8HUF/Qbqzc5ZPcTSX2RTHsCmRtAswEvmdEND/B2prYqfYnTzkVGjJPd71oGT6PK+Yok9bzxVf4HnNYtManIlSsi/uaS0+3gcY7//b88u8S37g==" Feb 23 23:16:46 volumio go-librespot[21729]: time="2026-02-23T23:16:46+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 23 23:16:47 volumio go-librespot[21729]: time="2026-02-23T23:16:47+07:00" level=debug msg="completed keyexchange" Feb 23 23:16:47 volumio go-librespot[21729]: time="2026-02-23T23:16:47+07:00" level=debug msg="completed challenge" Feb 23 23:16:47 volumio go-librespot[21729]: time="2026-02-23T23:16:47+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 23 23:16:47 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 23 23:16:47 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 23 23:16:47 volumio volumio[21396]: info: Connection to go-librespot Websocket closed Feb 23 23:16:49 volumio volumio[21396]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 23 23:16:49 volumio volumio[21396]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 23 23:16:49 volumio volumio[21396]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 23 23:16:49 volumio volumio[21396]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 23 23:16:49 volumio volumio[21396]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 23 23:16:49 volumio volumio[21396]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 23 23:16:49 volumio volumio[21396]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 23 23:16:49 volumio volumio[21396]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 23 23:16:49 volumio volumio[21396]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 23 23:16:49 volumio volumio[21396]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 23 23:16:49 volumio volumio[21396]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 23 23:16:49 volumio volumio[21396]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 23 23:16:49 volumio volumio[21396]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 23 23:16:49 volumio volumio[21396]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 23 23:16:49 volumio volumio[21396]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 23 23:16:49 volumio volumio[21396]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 23 23:16:49 volumio volumio[21396]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 23 23:16:49 volumio volumio[21396]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 23 23:16:49 volumio volumio[21396]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 23 23:16:49 volumio volumio[21396]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 23 23:16:49 volumio volumio[21396]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 23 23:16:49 volumio volumio[21396]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 23 23:16:49 volumio volumio[21396]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 23 23:16:49 volumio volumio[21396]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 23 23:16:49 volumio volumio[21396]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 23 23:16:49 volumio volumio[21396]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 23 23:16:49 volumio volumio[21396]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 23 23:16:49 volumio volumio[21396]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 23 23:16:49 volumio volumio[21396]: info: Adding plugin bluetooth to MyMusic Plugins Feb 23 23:16:49 volumio volumio[21396]: info: Adding plugin multiroom to MyMusic Plugins Feb 23 23:16:49 volumio volumio[21396]: info: Adding plugin metavolumio to MyMusic Plugins Feb 23 23:16:49 volumio volumio[21396]: info: Adding plugin cd_controller to MyMusic Plugins Feb 23 23:16:49 volumio volumio[21396]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 23 23:16:49 volumio volumio[21396]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 23 23:16:49 volumio volumio[21396]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 23 23:16:49 volumio volumio[21396]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 23 23:16:50 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Feb 23 23:16:50 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 23 23:16:50 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 23 23:16:50 volumio go-librespot[21751]: go-librespot daemon starting... Feb 23 23:16:50 volumio go-librespot[21752]: time="2026-02-23T23:16:50+07:00" level=info msg="running go-librespot 0.4.0" Feb 23 23:16:50 volumio go-librespot[21752]: time="2026-02-23T23:16:50+07:00" level=debug msg="app state loaded" Feb 23 23:16:50 volumio go-librespot[21752]: time="2026-02-23T23:16:50+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 23 23:16:50 volumio volumio[21396]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 23 23:16:50 volumio volumio[21396]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 23 23:16:50 volumio volumio[21396]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 23 23:16:50 volumio volumio[21396]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 23 23:16:50 volumio volumio[21396]: info: Starting MyVolumio Remote Streaming Endpoints Feb 23 23:16:50 volumio volumio[21396]: info: MyVolumio login type: Token Feb 23 23:16:51 volumio volumio[21396]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 23 23:16:51 volumio volumio[21396]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 23 23:16:51 volumio go-librespot[21752]: time="2026-02-23T23:16:51+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 23 23:16:51 volumio go-librespot[21752]: time="2026-02-23T23:16:51+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 23 23:16:51 volumio go-librespot[21752]: time="2026-02-23T23:16:51+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 23 23:16:51 volumio go-librespot[21752]: time="2026-02-23T23:16:51+07:00" level=info msg="zeroconf server listening on port 42689" Feb 23 23:16:51 volumio go-librespot[21752]: time="2026-02-23T23:16:51+07:00" level=debug msg="obtained new client token: AAAcEWyqcJL3AUsDNrkSeeyim2gBM3A5aLc8E3kXJGcnqvzjuQEnDd78hQvzMADecZQ6mtNpjXnczU3wo90EHsAesCFJlSQi2+7jRjL5GuDspQorA4fWLzuRbJatRyNKEEFoOTmzkapRlJeaf1UkPCeyRYIcz7grpOQBPEaFwbN9bYHxAuecadF7mMhXXMC9ndm18EqFmeUEeceWK2WjOVSm/mno7O51KbKspoMdaiJt4jlzsxCcZSomFA==" Feb 23 23:16:51 volumio go-librespot[21752]: time="2026-02-23T23:16:51+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 23 23:16:51 volumio go-librespot[21752]: time="2026-02-23T23:16:51+07:00" level=debug msg="completed keyexchange" Feb 23 23:16:51 volumio go-librespot[21752]: time="2026-02-23T23:16:51+07:00" level=debug msg="completed challenge" Feb 23 23:16:51 volumio go-librespot[21752]: time="2026-02-23T23:16:51+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 23 23:16:51 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 23 23:16:51 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 23 23:16:52 volumio volumio[21396]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 23 23:16:52 volumio volumio[21396]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 23 23:16:52 volumio volumio[21396]: info: Streaming services startup Feb 23 23:16:52 volumio volumio[21396]: info: Starting Streaming Daemon Feb 23 23:16:52 volumio sudo[21761]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 23 23:16:52 volumio sudo[21761]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 23:16:52 volumio volumio[21396]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 23 23:16:52 volumio sudo[21761]: pam_unix(sudo:session): session closed for user root Feb 23 23:16:53 volumio volumio[21396]: info: Getting Spotify volume Feb 23 23:16:53 volumio volumio[21396]: info: Initializing connection to go-librespot Websocket Feb 23 23:16:53 volumio volumio[21396]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 23 23:16:53 volumio volumio[21396]: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 23 23:16:53 volumio volumio[21396]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Feb 23 23:16:53 volumio volumio[21396]: errno: -111, Feb 23 23:16:53 volumio volumio[21396]: code: 'ECONNREFUSED', Feb 23 23:16:53 volumio volumio[21396]: syscall: 'connect', Feb 23 23:16:53 volumio volumio[21396]: address: '127.0.0.1', Feb 23 23:16:53 volumio volumio[21396]: port: 9879, Feb 23 23:16:53 volumio volumio[21396]: response: undefined Feb 23 23:16:53 volumio volumio[21396]: } Feb 23 23:16:53 volumio volumio[21396]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 23 23:16:54 volumio sudo[21781]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-23 23:15' Feb 23 23:16:54 volumio sudo[21781]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 23:16:54 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Feb 23 23:16:54 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 23 23:16:54 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 23 23:16:54 volumio go-librespot[21783]: go-librespot daemon starting... Feb 23 23:16:54 volumio go-librespot[21784]: time="2026-02-23T23:16:54+07:00" level=info msg="running go-librespot 0.4.0" Feb 23 23:16:54 volumio go-librespot[21784]: time="2026-02-23T23:16:54+07:00" level=debug msg="app state loaded" Feb 23 23:16:54 volumio go-librespot[21784]: time="2026-02-23T23:16:54+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 23 23:16:55 volumio sudo[21781]: pam_unix(sudo:session): session closed for user root Feb 23 23:16:55 volumio volumio-remote-updater[647]: [2026-02-23 23:16:55] [error] handle_read_frame error: asio.system:104 (Connection reset by peer) Feb 23 23:16:55 volumio volumio-remote-updater[647]: [2026-02-23 23:16:55] [disconnect] Disconnect close local:[1006,Connection reset by peer] remote:[1006] Feb 23 23:16:55 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Feb 23 23:16:55 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Feb 23 23:16:55 volumio systemd[1]: volumio.service: Consumed 1min 6.482s CPU time. Feb 23 23:16:55 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 23 23:16:55 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 23 23:16:55 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 5874. Feb 23 23:16:55 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Feb 23 23:16:55 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Feb 23 23:16:55 volumio systemd[1]: volumio.service: Consumed 1min 6.482s CPU time. Feb 23 23:16:55 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Feb 23 23:16:55 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Feb 23 23:16:55 volumio go-librespot[21784]: time="2026-02-23T23:16:55+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 23 23:16:55 volumio go-librespot[21784]: time="2026-02-23T23:16:55+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 23 23:16:55 volumio go-librespot[21784]: time="2026-02-23T23:16:55+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 23 23:16:55 volumio go-librespot[21784]: time="2026-02-23T23:16:55+07:00" level=info msg="zeroconf server listening on port 37265" Feb 23 23:16:55 volumio go-librespot[21784]: time="2026-02-23T23:16:55+07:00" level=debug msg="obtained new client token: AADKJY3/A2LAdObnzg0paNYB8NT5VipkftJ2AuDsHQMVuxT9YigIV6mUxhuuO/xoGhL4oN46iUdxW995/sUOKskPj7pE/rQMx3hJJ+pSJmh4BPSahJq67Ei+DJPf0HMYX6ksrMBunSfj+hKc1arLvYbeV1YjbQygk/P1CANeCjwCm+rby6oh+hZwfP1JO/KEOI0gt78/faYsNQOYs2/vmeS5stCAN6J7V64uf2nNTGHqK7AGizE1X0zWLA==" Feb 23 23:16:56 volumio go-librespot[21784]: time="2026-02-23T23:16:56+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 23 23:16:56 volumio go-librespot[21784]: time="2026-02-23T23:16:56+07:00" level=debug msg="completed keyexchange" Feb 23 23:16:56 volumio go-librespot[21784]: time="2026-02-23T23:16:56+07:00" level=debug msg="completed challenge" Feb 23 23:16:56 volumio go-librespot[21784]: time="2026-02-23T23:16:56+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 23 23:16:56 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 23 23:16:56 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 23 23:16:59 volumio volumio[21804]: info: ------------------------------------------- Feb 23 23:16:59 volumio volumio[21804]: info: ----- Volumio3 ---- Feb 23 23:16:59 volumio volumio[21804]: info: ------------------------------------------- Feb 23 23:16:59 volumio volumio[21804]: info: ----- System startup ---- Feb 23 23:16:59 volumio volumio[21804]: info: ------------------------------------------- Feb 23 23:16:59 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Feb 23 23:16:59 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 23 23:16:59 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 23 23:16:59 volumio go-librespot[21827]: go-librespot daemon starting... Feb 23 23:16:59 volumio go-librespot[21828]: time="2026-02-23T23:16:59+07:00" level=info msg="running go-librespot 0.4.0" Feb 23 23:16:59 volumio go-librespot[21828]: time="2026-02-23T23:16:59+07:00" level=debug msg="app state loaded" Feb 23 23:16:59 volumio go-librespot[21828]: time="2026-02-23T23:16:59+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 23 23:17:00 volumio go-librespot[21828]: time="2026-02-23T23:17:00+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 23 23:17:00 volumio go-librespot[21828]: time="2026-02-23T23:17:00+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 23 23:17:00 volumio go-librespot[21828]: time="2026-02-23T23:17:00+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 23 23:17:00 volumio go-librespot[21828]: time="2026-02-23T23:17:00+07:00" level=info msg="zeroconf server listening on port 45509" Feb 23 23:17:00 volumio volumio-remote-updater[647]: [2026-02-23 23:17:00] [connect] Successful connection Feb 23 23:17:00 volumio go-librespot[21828]: time="2026-02-23T23:17:00+07:00" level=debug msg="obtained new client token: AACvX0o6ZiuBCo+3Nab+SeFvf72QbuPsxiacnnbVPUUiA/WEHDiyC7ztqA3CWoTYetCl5S64Ti8GcIY2HJPHmvZMbaNSBZ+88FXim2ylgR6IHItxaFLa+pZ7uzzF1v9XPq7KRgwgEJu6YyrZoh8zKr8cDXju3vvWpCyCoT7QyRcohP6/yrJXBaYQGiRJ62Sfay1Flj/sxgdtxm2XTUknqwbM+wH7yfKyp+Y3g8kttOUc/2Yt0IUPCP5cvA==" Feb 23 23:17:00 volumio go-librespot[21828]: time="2026-02-23T23:17:00+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Feb 23 23:17:00 volumio volumio[21804]: info: MYVOLUMIO Environment detected Feb 23 23:17:00 volumio go-librespot[21828]: time="2026-02-23T23:17:00+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 23 23:17:00 volumio volumio[21804]: info: Plugin folders cleanup Feb 23 23:17:00 volumio volumio[21804]: info: Scanning into folder /volumio/app/plugins/ Feb 23 23:17:00 volumio volumio[21804]: info: Scanning category audio_interface Feb 23 23:17:00 volumio go-librespot[21828]: time="2026-02-23T23:17:00+07:00" level=debug msg="completed keyexchange" Feb 23 23:17:00 volumio go-librespot[21828]: time="2026-02-23T23:17:00+07:00" level=debug msg="completed challenge" Feb 23 23:17:00 volumio volumio[21804]: info: Scanning category miscellanea Feb 23 23:17:00 volumio volumio[21804]: info: Scanning category music_service Feb 23 23:17:00 volumio volumio[21804]: info: Scanning category plugins.json Feb 23 23:17:00 volumio volumio[21804]: info: Scanning category system_controller Feb 23 23:17:00 volumio volumio[21804]: info: Scanning category user_interface Feb 23 23:17:00 volumio volumio[21804]: info: Scanning into folder /data/plugins/ Feb 23 23:17:00 volumio volumio[21804]: info: Scanning category music_service Feb 23 23:17:00 volumio volumio[21804]: info: Plugin folders cleanup completed Feb 23 23:17:00 volumio volumio[21804]: info: ------------------------------------------- Feb 23 23:17:00 volumio volumio[21804]: info: ----- Core plugins startup ---- Feb 23 23:17:00 volumio volumio[21804]: info: ------------------------------------------- Feb 23 23:17:00 volumio volumio[21804]: info: Loading plugins from folder /volumio/app/plugins/ Feb 23 23:17:00 volumio volumio[21804]: info: Adding plugin upnp to MyMusic Plugins Feb 23 23:17:00 volumio volumio[21804]: info: Adding plugin airplay_emulation to MyMusic Plugins Feb 23 23:17:00 volumio volumio[21804]: info: Adding plugin upnp_browser to MyMusic Plugins Feb 23 23:17:00 volumio volumio[21804]: info: Loading plugins from folder /data/plugins/ Feb 23 23:17:00 volumio volumio[21804]: info: Loading plugin "system"... Feb 23 23:17:00 volumio go-librespot[21828]: time="2026-02-23T23:17: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 23 23:17:00 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 23 23:17:00 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 23 23:17:00 volumio volumio[21804]: info: Loading plugin "appearance"... Feb 23 23:17:02 volumio volumio[21804]: info: Loading plugin "network"... Feb 23 23:17:02 volumio volumio[21804]: info: Refreshing Cached IP Addresses Feb 23 23:17:02 volumio sudo[21843]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 23 23:17:02 volumio sudo[21843]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 23:17:02 volumio sudo[21845]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 23 23:17:02 volumio sudo[21845]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 23:17:02 volumio sudo[21845]: pam_unix(sudo:session): session closed for user root Feb 23 23:17:02 volumio sudo[21843]: pam_unix(sudo:session): session closed for user root Feb 23 23:17:02 volumio volumio[21804]: info: Loading plugin "services"... Feb 23 23:17:02 volumio volumio[21804]: info: Loading plugin "alsa_controller"... Feb 23 23:17:02 volumio sudo[21854]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Feb 23 23:17:02 volumio sudo[21854]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 23:17:03 volumio volumio[21804]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 23 23:17:03 volumio volumio[21804]: info: Loading plugin "wizard"... Feb 23 23:17:03 volumio volumio[21804]: info: Loading plugin "networkfs"... Feb 23 23:17:03 volumio volumio[21804]: info: Starting Udev Watcher for removable devices Feb 23 23:17:03 volumio volumio[21804]: info: Ignoring mount for partition: boot Feb 23 23:17:03 volumio volumio[21804]: info: Ignoring mount for partition: volumio Feb 23 23:17:03 volumio volumio[21804]: info: Ignoring mount for partition: volumio_data Feb 23 23:17:03 volumio volumio[21804]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 23 23:17:03 volumio volumio[21804]: info: Loading plugin "volumio_command_line_client"... Feb 23 23:17:03 volumio volumio[21804]: info: Loading plugin "upnp"... Feb 23 23:17:03 volumio volumio[21804]: info: [1771863423241] Starting Upmpd Daemon Feb 23 23:17:03 volumio volumio[21804]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 23 23:17:03 volumio volumio[21804]: info: Loading plugin "my_music"... Feb 23 23:17:03 volumio volumio[21804]: info: Loading plugin "mpd"... Feb 23 23:17:03 volumio volumio[21804]: info: Loading plugin "upnp_browser"... Feb 23 23:17:04 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15. Feb 23 23:17:04 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 23 23:17:04 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 23 23:17:04 volumio go-librespot[21876]: go-librespot daemon starting... Feb 23 23:17:04 volumio go-librespot[21877]: time="2026-02-23T23:17:04+07:00" level=info msg="running go-librespot 0.4.0" Feb 23 23:17:04 volumio go-librespot[21877]: time="2026-02-23T23:17:04+07:00" level=debug msg="app state loaded" Feb 23 23:17:04 volumio go-librespot[21877]: time="2026-02-23T23:17:04+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 23 23:17:04 volumio go-librespot[21877]: time="2026-02-23T23:17:04+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 23 23:17:04 volumio go-librespot[21877]: time="2026-02-23T23:17:04+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Feb 23 23:17:04 volumio go-librespot[21877]: time="2026-02-23T23:17:04+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Feb 23 23:17:04 volumio go-librespot[21877]: time="2026-02-23T23:17:04+07:00" level=info msg="zeroconf server listening on port 36931" Feb 23 23:17:05 volumio go-librespot[21877]: time="2026-02-23T23:17:05+07:00" level=debug msg="obtained new client token: AADURNQrTPnMOPPLarIM4n1RYe0IokdM2ItY3H+mUpXbdwfn9GQ4qoiot6CwDup8+uanaRHDX+S4vsOKuPb0WM7q2KNrxTLl0kgPv8S+vcWJbMBZRAsE8eAv24CErRLSQ+XxFgLMKUDcmQ0HT1aHqhL2CtELGz0/EAKo20h2ay4+ViKEuTPY9FmP35IXTGuDlFa/jly7yIjeml+6tXZXyWcZ2d2eSU6La05aKjuMOyxrTFrim+rLAVM=" Feb 23 23:17:05 volumio go-librespot[21877]: time="2026-02-23T23:17:05+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 23 23:17:05 volumio go-librespot[21877]: time="2026-02-23T23:17:05+07:00" level=debug msg="completed keyexchange" Feb 23 23:17:05 volumio go-librespot[21877]: time="2026-02-23T23:17:05+07:00" level=debug msg="completed challenge" Feb 23 23:17:05 volumio go-librespot[21877]: time="2026-02-23T23:17: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 23 23:17:05 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 23 23:17:05 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 23 23:17:05 volumio sudo[21854]: pam_unix(sudo:session): session closed for user root Feb 23 23:17:06 volumio volumio[21804]: info: Starting UPNP Browser Feb 23 23:17:06 volumio volumio[21804]: info: Loading plugin "alarm-clock"... Feb 23 23:17:07 volumio volumio[21804]: info: Loading plugin "airplay_emulation"... Feb 23 23:17:07 volumio volumio[21804]: info: Starting Shairport Sync Feb 23 23:17:07 volumio volumio[21804]: info: Loading plugin "last_100"... Feb 23 23:17:07 volumio volumio[21804]: info: Loading plugin "webradio"... Feb 23 23:17:07 volumio volumio[21804]: info: Loading plugin "i2s_dacs"... Feb 23 23:17:07 volumio volumio[21804]: info: Loading plugin "volumiodiscovery"... Feb 23 23:17:07 volumio volumio[21804]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 23 23:17:07 volumio volumio[21804]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 23 23:17:07 volumio node[21804]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Feb 23 23:17:07 volumio volumio[21804]: *** WARNING *** For more information see Feb 23 23:17:07 volumio volumio[21804]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 23 23:17:07 volumio volumio[21804]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 23 23:17:07 volumio volumio[21804]: *** WARNING *** For more information see Feb 23 23:17:07 volumio node[21804]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 23 23:17:07 volumio node[21804]: *** WARNING *** For more information see Feb 23 23:17:07 volumio node[21804]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Feb 23 23:17:07 volumio node[21804]: *** WARNING *** Please fix your application to use the native API of Avahi! Feb 23 23:17:07 volumio node[21804]: *** WARNING *** For more information see Feb 23 23:17:07 volumio volumio[21804]: info: Applying required configuration parameters for plugin volumiodiscovery Feb 23 23:17:07 volumio volumio[21804]: info: Discovery: Started advertising with name: Volumio Feb 23 23:17:07 volumio volumio[21804]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Feb 23 23:17:07 volumio volumio[21804]: info: Loading plugin "spop"... Feb 23 23:17:08 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Feb 23 23:17:08 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 23 23:17:08 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 23 23:17:08 volumio go-librespot[21886]: go-librespot daemon starting... Feb 23 23:17:08 volumio go-librespot[21887]: time="2026-02-23T23:17:08+07:00" level=info msg="running go-librespot 0.4.0" Feb 23 23:17:08 volumio go-librespot[21887]: time="2026-02-23T23:17:08+07:00" level=debug msg="app state loaded" Feb 23 23:17:08 volumio go-librespot[21887]: time="2026-02-23T23:17:08+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 23 23:17:09 volumio go-librespot[21887]: time="2026-02-23T23:17: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 23 23:17:09 volumio go-librespot[21887]: time="2026-02-23T23:17: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 23 23:17:09 volumio go-librespot[21887]: time="2026-02-23T23:17: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 23 23:17:09 volumio go-librespot[21887]: time="2026-02-23T23:17:09+07:00" level=info msg="zeroconf server listening on port 44635" Feb 23 23:17:09 volumio volumio[21804]: info: Loading plugin "ytcr"... Feb 23 23:17:09 volumio go-librespot[21887]: time="2026-02-23T23:17:09+07:00" level=debug msg="obtained new client token: AACIbjMo++90c6s05iuu6JmRwBltjZu3qDnpyW0p/nHXtBWr7bv2C/OOSbHfe76kQJlWVCurgXpDirtiUqdCM5PP0Zo892Mv74ERJIhGJa2KNICwz6uqXu3OBtt5JZsMjjeRIlD8mcM3Tz7b/ogEg/uTE2rutBzK/02U8NvPricACGz92Cm0LlAiVbPivKsIGWCYImzlxgx2665LTyoXnmT45pEcaPAZ6VyIkGxgAy9SdiS2db6VK1gp4g==" Feb 23 23:17:09 volumio go-librespot[21887]: time="2026-02-23T23:17:09+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 23 23:17:09 volumio go-librespot[21887]: time="2026-02-23T23:17:09+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Feb 23 23:17:09 volumio go-librespot[21887]: time="2026-02-23T23:17:09+07:00" level=debug msg="completed keyexchange" Feb 23 23:17:09 volumio go-librespot[21887]: time="2026-02-23T23:17:09+07:00" level=debug msg="completed challenge" Feb 23 23:17:10 volumio go-librespot[21887]: time="2026-02-23T23:17:10+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 23 23:17:10 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 23 23:17:10 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 23 23:17:12 volumio volumio[21804]: info: Loading plugin "ytmusic"... Feb 23 23:17:12 volumio volumio-remote-updater[647]: [2026-02-23 23:17:12] [connect] Successful connection Feb 23 23:17:13 volumio volumio[21804]: info: Loading plugin "outputs"... Feb 23 23:17:13 volumio volumio[21804]: info: Loading plugin "albumart"... Feb 23 23:17:13 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17. Feb 23 23:17:13 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 23 23:17:13 volumio volumio[21804]: info: Plugin example_plugin is not enabled Feb 23 23:17:13 volumio volumio[21804]: info: Loading plugin "inputs"... Feb 23 23:17:13 volumio volumio[21804]: info: Loading plugin "updater_comm"... Feb 23 23:17:13 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 23 23:17:13 volumio go-librespot[21913]: go-librespot daemon starting... Feb 23 23:17:13 volumio go-librespot[21922]: time="2026-02-23T23:17:13+07:00" level=info msg="running go-librespot 0.4.0" Feb 23 23:17:13 volumio go-librespot[21922]: time="2026-02-23T23:17:13+07:00" level=debug msg="app state loaded" Feb 23 23:17:13 volumio go-librespot[21922]: time="2026-02-23T23:17:13+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 23 23:17:13 volumio volumio[21804]: info: Plugin mpdemulation is not enabled Feb 23 23:17:13 volumio volumio[21804]: info: Loading plugin "rest_api"... Feb 23 23:17:13 volumio volumio[21804]: info: Loading plugin "websocket"... Feb 23 23:17:13 volumio volumio[21804]: info: Starting Socket.io Server version 1.7.4 Feb 23 23:17:13 volumio volumio[21804]: info: Loading plugin "RoonBridge"... Feb 23 23:17:14 volumio go-librespot[21922]: time="2026-02-23T23:17:14+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 23 23:17:14 volumio go-librespot[21922]: time="2026-02-23T23:17:14+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 23 23:17:14 volumio go-librespot[21922]: time="2026-02-23T23:17:14+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 23 23:17:14 volumio go-librespot[21922]: time="2026-02-23T23:17:14+07:00" level=info msg="zeroconf server listening on port 34949" Feb 23 23:17:14 volumio go-librespot[21922]: time="2026-02-23T23:17:14+07:00" level=debug msg="obtained new client token: AADOO3KZGcHZa5xcZpEDNy2GPdh6r3tYqBg0eHpb6g52+NrTvfcmeM1nKDWkKWfxOgPnWa5X2EYmKPRasmXMXd2Aij+GxQ59zXscHZxbTRZsiZ/0sTBxXN2Gxq8RDZQ8PADqY9YjE8KWukcfVCHQdgoqhV7lzqVqYiph/b7Hl/j/s7Ci1cJny1H7jXzY6Aa6D460N85mss70c5PCbjtnOIA7BJ9iWuAhYc7LkBepIyktg2b1sRt1B69itg==" Feb 23 23:17:14 volumio volumio[21804]: info: Applying required configuration parameters for plugin RoonBridge Feb 23 23:17:14 volumio go-librespot[21922]: time="2026-02-23T23:17:14+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 23 23:17:14 volumio volumio[21804]: info: Loading i18n strings for locale en Feb 23 23:17:14 volumio volumio[21804]: Updating browse sources language Feb 23 23:17:14 volumio volumio[21804]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 23 23:17:14 volumio go-librespot[21922]: time="2026-02-23T23:17:14+07:00" level=debug msg="completed keyexchange" Feb 23 23:17:14 volumio go-librespot[21922]: time="2026-02-23T23:17:14+07:00" level=debug msg="completed challenge" Feb 23 23:17:14 volumio go-librespot[21922]: time="2026-02-23T23:17: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 23 23:17:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 23 23:17:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 23 23:17:14 volumio volumio[21912]: Forking 3 albumart workers Feb 23 23:17:14 volumio volumio[21804]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 23 23:17:14 volumio volumio[21804]: info: CoreCommandRouter::initPlayerControls Feb 23 23:17:14 volumio volumio[21804]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 23:17:14 volumio volumio[21804]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 23:17:14 volumio volumio[21804]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 23:17:14 volumio volumio[21804]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 23:17:14 volumio volumio[21804]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 23:17:14 volumio volumio[21804]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 23:17:14 volumio volumio[21804]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 23:17:14 volumio volumio[21804]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 23:17:14 volumio volumio[21804]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 23 23:17:14 volumio volumio[21804]: Express server listening on port 3000 Feb 23 23:17:14 volumio volumio[21804]: [Metrics] WebUI: 16s 659.38ms Feb 23 23:17:14 volumio volumio[21804]: info: CoreStateMachine::resetVolumioState Feb 23 23:17:14 volumio volumio[21804]: info: CoreStateMachine::getcurrentVolume Feb 23 23:17:14 volumio volumio[21804]: info: CoreCommandRouter::volumioRetrievevolume Feb 23 23:17:15 volumio sudo[21963]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 23 23:17:15 volumio sudo[21963]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 23:17:15 volumio sudo[21963]: pam_unix(sudo:session): session closed for user root Feb 23 23:17:15 volumio sudo[21967]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 23 23:17:15 volumio sudo[21967]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 23:17:15 volumio sudo[21967]: pam_unix(sudo:session): session closed for user root Feb 23 23:17:15 volumio volumio[21804]: info: Volumio Network Manager: Network status updated: 1 Feb 23 23:17:15 volumio volumio-remote-updater[647]: [2026-02-23 23:17:15] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1771863432 101 Feb 23 23:17:15 volumio volumio[21804]: 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 23 23:17:15 volumio volumio[21804]: info: VolumeController:: Volume=100 Mute =false Feb 23 23:17:15 volumio volumio[21804]: info: CoreStateMachine::pushState Feb 23 23:17:15 volumio volumio[21804]: info: CorePlayQueue::getTrack 0 Feb 23 23:17:15 volumio volumio[21804]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 23 23:17:15 volumio volumio[21804]: info: CoreCommandRouter::volumioPushState Feb 23 23:17:15 volumio volumio[21804]: info: CoreStateMachine::updateTrackBlock Feb 23 23:17:15 volumio volumio[21804]: info: CorePlayQueue::getTrackBlock Feb 23 23:17:15 volumio volumio[21804]: info: CoreCommandRouter::volumioRetrievevolume Feb 23 23:17:15 volumio volumio[21804]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 23 23:17:15 volumio volumio[21804]: info: Reloading queue from file Feb 23 23:17:15 volumio volumio[21804]: info: CoreStateMachine::setRepeat null single undefined Feb 23 23:17:15 volumio volumio[21804]: info: CoreStateMachine::pushState Feb 23 23:17:15 volumio volumio[21804]: info: CorePlayQueue::getTrack 0 Feb 23 23:17:15 volumio volumio[21804]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Feb 23 23:17:15 volumio volumio[21804]: info: CoreCommandRouter::volumioPushState Feb 23 23:17:15 volumio volumio[21804]: info: CoreStateMachine::setRandom null Feb 23 23:17:15 volumio volumio[21804]: info: CoreStateMachine::pushState Feb 23 23:17:15 volumio volumio[21804]: info: CorePlayQueue::getTrack 0 Feb 23 23:17:15 volumio volumio[21804]: info: CoreCommandRouter::volumioPushState Feb 23 23:17:15 volumio volumio[21804]: info: Setting Device type: Raspberry PI Feb 23 23:17:15 volumio volumio[21804]: info: Completed loading Core Plugins Feb 23 23:17:15 volumio volumio[21804]: info: Preparing to generate the ALSA configuration file Feb 23 23:17:16 volumio volumio[21804]: info: VolumeController:: Volume=100 Mute =false Feb 23 23:17:16 volumio volumio[21804]: info: CoreStateMachine::pushState Feb 23 23:17:16 volumio volumio[21804]: info: CorePlayQueue::getTrack 0 Feb 23 23:17:16 volumio volumio[21804]: info: CoreCommandRouter::volumioPushState Feb 23 23:17:16 volumio volumio[21804]: info: Asound.conf file unchanged, so no further update is needed Feb 23 23:17:16 volumio volumio[21804]: info: Output device has changed, restarting MPD Feb 23 23:17:16 volumio sudo[21981]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 23 23:17:16 volumio sudo[21981]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 23:17:16 volumio sudo[21984]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 23 23:17:16 volumio volumio[21804]: info: Output device has changed, restarting Shairport Sync Feb 23 23:17:16 volumio sudo[21984]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 23:17:16 volumio volumio[21804]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 23:17:16 volumio volumio[21804]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 23 23:17:16 volumio sudo[21984]: pam_unix(sudo:session): session closed for user root Feb 23 23:17:16 volumio sudo[21981]: pam_unix(sudo:session): session closed for user root Feb 23 23:17:16 volumio volumio[21804]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 23 23:17:16 volumio volumio[21804]: info: ___________ START PLUGINS ___________ Feb 23 23:17:16 volumio volumio[21804]: info: ControllerMpd::onStart: Initializing MPD Feb 23 23:17:16 volumio volumio[21804]: info: Creating MPD Configuration file Feb 23 23:17:16 volumio sudo[21990]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 23 23:17:16 volumio sudo[21990]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 23:17:16 volumio volumio[21804]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Feb 23 23:17:16 volumio volumio[21804]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 23 23:17:16 volumio volumio[21804]: info: [1771863436393] CoreMusicLibrary::Adding element Media Servers Feb 23 23:17:16 volumio volumio[21804]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 23 23:17:16 volumio volumio[21804]: info: UPNP Browser: Client initialized successfully Feb 23 23:17:16 volumio sudo[21994]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Feb 23 23:17:16 volumio sudo[21994]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 23:17:16 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Feb 23 23:17:16 volumio sudo[21994]: pam_unix(sudo:session): session closed for user root Feb 23 23:17:16 volumio sudo[21997]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Feb 23 23:17:16 volumio volumio[21804]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 23:17:16 volumio sudo[21997]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 23:17:16 volumio volumio[21804]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 23 23:17:16 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 23 23:17:16 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 23 23:17:16 volumio systemd[1]: mpd.service: Consumed 6.980s CPU time. Feb 23 23:17:16 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 23 23:17:16 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 23 23:17:16 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 23 23:17:16 volumio volumio[21804]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 23 23:17:16 volumio volumio[21804]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 23:17:16 volumio volumio[21804]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 23 23:17:16 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 23 23:17:16 volumio volumio[21804]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Feb 23 23:17:16 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 23 23:17:16 volumio volumio[21804]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 23 23:17:16 volumio volumio[21804]: info: [1771863436836] CoreMusicLibrary::Adding element Last_100 Feb 23 23:17:16 volumio volumio[21804]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 23 23:17:16 volumio volumio[21804]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 23 23:17:16 volumio volumio[21804]: info: [1771863436882] CoreMusicLibrary::Adding element Webradio Feb 23 23:17:16 volumio volumio[21804]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 23 23:17:16 volumio systemd[1]: mpd.service: Deactivated successfully. Feb 23 23:17:16 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Feb 23 23:17:16 volumio systemd[1]: mpd.socket: Deactivated successfully. Feb 23 23:17:16 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Feb 23 23:17:16 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Feb 23 23:17:16 volumio volumio[21804]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 23 23:17:16 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Feb 23 23:17:16 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Feb 23 23:17:16 volumio volumio[21804]: info: Initializing BBC Radios Feb 23 23:17:17 volumio volumio[21804]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Feb 23 23:17:17 volumio volumio[21804]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 23 23:17:17 volumio volumio[21804]: info: Creating Spotify config file Feb 23 23:17:17 volumio volumio[21804]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 23:17:17 volumio sudo[22011]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Feb 23 23:17:17 volumio sudo[22011]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Feb 23 23:17:17 volumio sudo[22011]: pam_unix(sudo:session): session closed for user root Feb 23 23:17:17 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18. Feb 23 23:17:17 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 23 23:17:17 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 23 23:17:17 volumio go-librespot[22027]: go-librespot daemon starting... Feb 23 23:17:18 volumio go-librespot[22028]: time="2026-02-23T23:17:18+07:00" level=info msg="running go-librespot 0.4.0" Feb 23 23:17:18 volumio go-librespot[22028]: time="2026-02-23T23:17:18+07:00" level=info msg="zeroconf server listening on port 34375" Feb 23 23:17:18 volumio volumio[21804]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 23 23:17:18 volumio volumio[21804]: info: [1771863438859] CoreMusicLibrary::Adding element YouTube Music Feb 23 23:17:18 volumio volumio[21804]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 23 23:17:18 volumio volumio[21804]: Cannot find translation for source YouTube Music Feb 23 23:17:18 volumio volumio[21804]: info: Volumio Calling Home Feb 23 23:17:18 volumio sudo[22036]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Feb 23 23:17:18 volumio sudo[22036]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 23:17:19 volumio sudo[22036]: pam_unix(sudo:session): session closed for user root Feb 23 23:17:19 volumio volumio[21931]: Starting albumart workers Feb 23 23:17:19 volumio volumio[21933]: Starting albumart workers Feb 23 23:17:19 volumio volumio[21804]: info: MPD Permissions set Feb 23 23:17:19 volumio volumio[21804]: info: MPD Permissions set Feb 23 23:17:20 volumio volumio[21804]: info: Upmpdcli Daemon Started Feb 23 23:17:20 volumio volumio[21804]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Feb 23 23:17:20 volumio volumio[21804]: info: Discovery: Found device Volumio Feb 23 23:17:20 volumio volumio[21804]: info: CoreCommandRouter::volumioGetState Feb 23 23:17:20 volumio volumio[21804]: info: CorePlayQueue::getTrack 0 Feb 23 23:17:20 volumio volumio[21804]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Feb 23 23:17:20 volumio volumio[21804]: info: Discovery: Found device Volumio Feb 23 23:17:20 volumio volumio[21804]: info: CoreCommandRouter::volumioGetState Feb 23 23:17:20 volumio volumio[21804]: info: CorePlayQueue::getTrack 0 Feb 23 23:17:20 volumio volumio[21804]: info: Volumio called home Feb 23 23:17:20 volumio volumio[21804]: info: Spotify config file written Feb 23 23:17:20 volumio volumio[21932]: Starting albumart workers Feb 23 23:17:20 volumio sudo[22042]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Feb 23 23:17:20 volumio sudo[22042]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 23:17:20 volumio volumio[21804]: 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 23 23:17:20 volumio volumio[21804]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 23:17:20 volumio volumio[21804]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 23:17:20 volumio volumio[21804]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 23:17:20 volumio volumio[21804]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 23:17:20 volumio volumio[21804]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 23:17:20 volumio volumio[21804]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 23:17:20 volumio volumio[21804]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 23:17:20 volumio volumio[21804]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 23:17:20 volumio volumio[21804]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 23 23:17:20 volumio volumio[21804]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 23:17:20 volumio volumio[21804]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 23:17:20 volumio volumio[21804]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 23:17:20 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Feb 23 23:17:20 volumio volumio[21804]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 23:17:20 volumio volumio[21804]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 23:17:20 volumio volumio[21804]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 23:17:20 volumio volumio[21804]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 23:17:20 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Feb 23 23:17:20 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 23 23:17:20 volumio volumio[21804]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 23:17:20 volumio volumio[21804]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 23:17:20 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 23 23:17:20 volumio go-librespot[22049]: go-librespot daemon starting... Feb 23 23:17:20 volumio sudo[22042]: pam_unix(sudo:session): session closed for user root Feb 23 23:17:20 volumio volumio[21804]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 23 23:17:20 volumio volumio[21804]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Feb 23 23:17:20 volumio volumio[21804]: info: No need to fix Spotify hosts Feb 23 23:17:20 volumio go-librespot[22055]: time="2026-02-23T23:17:20+07:00" level=info msg="running go-librespot 0.4.0" Feb 23 23:17:20 volumio go-librespot[22055]: time="2026-02-23T23:17:20+07:00" level=debug msg="app state loaded" Feb 23 23:17:20 volumio go-librespot[22055]: time="2026-02-23T23:17:20+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 23 23:17:21 volumio go-librespot[22055]: time="2026-02-23T23:17:21+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 23 23:17:21 volumio go-librespot[22055]: time="2026-02-23T23:17:21+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 23 23:17:21 volumio go-librespot[22055]: time="2026-02-23T23:17:21+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 23 23:17:21 volumio go-librespot[22055]: time="2026-02-23T23:17:21+07:00" level=info msg="zeroconf server listening on port 36543" Feb 23 23:17:21 volumio go-librespot[22055]: time="2026-02-23T23:17:21+07:00" level=debug msg="obtained new client token: AAAyF6ofkMi/98MgdJpEKWzsmPVjmmDvkwwL7DL1mtLY8GLGL1CV9tiCuMB0U0CBJ0SKjL1JpBkSeZe2qWeszk44W7p0A6wqkJOSYuOqv4IjI6x2anAfJzC8806830MeUVJIfJT32QhOjmcNYzuvpRMzMDcl7hSJD3UHKTdJUWYUjjN46e1NWQgm62U9yZ7hsFKAbx5WSzXZFSk3qVfp6lykLFE+uzUoyI2vCjmqq6RCCxJjJtG7zbUzNQ==" Feb 23 23:17:21 volumio go-librespot[22055]: time="2026-02-23T23:17:21+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 23 23:17:22 volumio go-librespot[22055]: time="2026-02-23T23:17:22+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Feb 23 23:17:22 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 23 23:17:22 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 23 23:17:22 volumio volumio[21804]: info: Starting Shairport Sync Feb 23 23:17:22 volumio volumio[21804]: info: Starting Shairport Sync Feb 23 23:17:23 volumio volumio[21804]: info: Starting Shairport Sync Feb 23 23:17:23 volumio sudo[22075]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 23 23:17:23 volumio sudo[22075]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 23:17:23 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 23 23:17:23 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 23 23:17:23 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 23 23:17:23 volumio systemd[1]: shairport-sync.service: Consumed 2.298s CPU time. Feb 23 23:17:23 volumio sudo[22077]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 23 23:17:23 volumio sudo[22077]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 23:17:23 volumio sudo[22080]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Feb 23 23:17:23 volumio sudo[22080]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 23:17:23 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 23 23:17:23 volumio sudo[22075]: pam_unix(sudo:session): session closed for user root Feb 23 23:17:23 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Feb 23 23:17:23 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Feb 23 23:17:23 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 23 23:17:23 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Feb 23 23:17:23 volumio volumio[21804]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 23 23:17:23 volumio volumio[21804]: SPOTIFY: BQDB44teZpCXGhTmmZV2DngNog6FsveRwsrBaFmbYNl3L-18JtlBPGL8ryLJfnnWsLVFmzWf4OydALxNnuP9ym5o5dMvAFt-7GEN2J0rnumhx_hb3aJ4Zn3kgNqSPsKwWQkgl-aC2Jrp9izONBZHJNgJAOKat8UkuC0R_Y7Y1NCJ4W4AHr81tru6D-AHjIO7CUiAFK1c5yTxlsiHENNIq2fMeCGLZDsvqHmGpNolSeon1GJRM25V2kovrVKwhJS11ZISkoo4nilDPUmMOp1WA-ASX5hVXRvd-mQnBycn49BvP3EjkGzqE4ym Feb 23 23:17:23 volumio volumio[21804]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Feb 23 23:17:23 volumio volumio[21804]: info: New Spotify access token = BQDB44teZpCXGhTmmZV2DngNog6FsveRwsrBaFmbYNl3L-18JtlBPGL8ryLJfnnWsLVFmzWf4OydALxNnuP9ym5o5dMvAFt-7GEN2J0rnumhx_hb3aJ4Zn3kgNqSPsKwWQkgl-aC2Jrp9izONBZHJNgJAOKat8UkuC0R_Y7Y1NCJ4W4AHr81tru6D-AHjIO7CUiAFK1c5yTxlsiHENNIq2fMeCGLZDsvqHmGpNolSeon1GJRM25V2kovrVKwhJS11ZISkoo4nilDPUmMOp1WA-ASX5hVXRvd-mQnBycn49BvP3EjkGzqE4ym Feb 23 23:17:23 volumio volumio[21804]: info: Spotify credentials grant success - running version from March 24, 2019 Feb 23 23:17:23 volumio sudo[22077]: pam_unix(sudo:session): session closed for user root Feb 23 23:17:23 volumio sudo[22080]: pam_unix(sudo:session): session closed for user root Feb 23 23:17:23 volumio volumio[21804]: info: Shairport-Sync Started Feb 23 23:17:23 volumio volumio[21804]: Error adding Membership: Error: addMembership EINVAL Feb 23 23:17:23 volumio volumio[21804]: info: Shairport-Sync Started Feb 23 23:17:23 volumio volumio[21804]: info: Shairport-Sync Started Feb 23 23:17:23 volumio volumio[21804]: info: CoreCommandRouter::volumioGetState Feb 23 23:17:23 volumio volumio[21804]: info: CorePlayQueue::getTrack 0 Feb 23 23:17:24 volumio mpd[22026]: 2026-02-23T23:17:24 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Feb 23 23:17:24 volumio systemd[1]: Started mpd.service - Music Player Daemon. Feb 23 23:17:24 volumio sudo[21997]: pam_unix(sudo:session): session closed for user root Feb 23 23:17:24 volumio sudo[21990]: pam_unix(sudo:session): session closed for user root Feb 23 23:17:24 volumio volumio[21804]: error: MPD error: The expression evaluated to a falsy value: Feb 23 23:17:24 volumio volumio[21804]: assert.ok(self.idling) Feb 23 23:17:24 volumio volumio[21804]: error: The expression evaluated to a falsy value: Feb 23 23:17:24 volumio volumio[21804]: assert.ok(self.idling) Feb 23 23:17:24 volumio volumio[21804]: info: MPD running with PID22026 Feb 23 23:17:24 volumio volumio[21804]: ,establishing connection Feb 23 23:17:24 volumio volumio[21804]: error: updateQueue error: null Feb 23 23:17:24 volumio volumio[21804]: error: updateQueue error: null Feb 23 23:17:24 volumio volumio[21804]: 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 23 23:17:24 volumio volumio[21804]: info: Spotify Successfully logged in Feb 23 23:17:24 volumio volumio[21804]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Feb 23 23:17:24 volumio volumio[21804]: info: [1771863444863] CoreMusicLibrary::Adding element Spotify Feb 23 23:17:24 volumio volumio[21804]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Feb 23 23:17:24 volumio volumio[21804]: Cannot find translation for source YouTube Music Feb 23 23:17:24 volumio volumio[21804]: Cannot find translation for source Spotify Feb 23 23:17:25 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Feb 23 23:17:25 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 23 23:17:25 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 23 23:17:25 volumio go-librespot[22124]: go-librespot daemon starting... Feb 23 23:17:25 volumio go-librespot[22125]: time="2026-02-23T23:17:25+07:00" level=info msg="running go-librespot 0.4.0" Feb 23 23:17:25 volumio go-librespot[22125]: time="2026-02-23T23:17:25+07:00" level=debug msg="app state loaded" Feb 23 23:17:25 volumio go-librespot[22125]: time="2026-02-23T23:17:25+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 23 23:17:25 volumio volumio[21804]: info: [yt-cast-receiver] DIAL server listening on port 8098 Feb 23 23:17:25 volumio volumio[21804]: info: CoreCommandRouter::volumioRetrievevolume Feb 23 23:17:25 volumio volumio[21804]: info: VolumeController:: Volume=100 Mute =false Feb 23 23:17:25 volumio volumio[21804]: info: CoreCommandRouter::volumioGetState Feb 23 23:17:25 volumio volumio[21804]: info: CorePlayQueue::getTrack 0 Feb 23 23:17:25 volumio volumio[21804]: info: CoreStateMachine::pushState Feb 23 23:17:25 volumio volumio[21804]: info: CorePlayQueue::getTrack 0 Feb 23 23:17:25 volumio volumio[21804]: info: CoreCommandRouter::volumioPushState Feb 23 23:17:25 volumio go-librespot[22125]: time="2026-02-23T23:17:25+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 23 23:17:25 volumio go-librespot[22125]: time="2026-02-23T23:17:25+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 23 23:17:25 volumio go-librespot[22125]: time="2026-02-23T23:17:25+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 23 23:17:25 volumio go-librespot[22125]: time="2026-02-23T23:17:25+07:00" level=info msg="zeroconf server listening on port 41369" Feb 23 23:17:25 volumio volumio[21804]: info: go-librespot daemon successfully initialized Feb 23 23:17:26 volumio volumio[21804]: info: Completed starting Core Plugins Feb 23 23:17:26 volumio volumio[21804]: info: ------------------------------------------- Feb 23 23:17:26 volumio volumio[21804]: info: ----- MyVolumio plugins startup ---- Feb 23 23:17:26 volumio volumio[21804]: info: ------------------------------------------- Feb 23 23:17:26 volumio volumio[21804]: info: [MyVolumio PluginManager] Fetching plans data.... Feb 23 23:17:26 volumio go-librespot[22125]: time="2026-02-23T23:17:26+07:00" level=debug msg="obtained new client token: AAAzibimdrP9dKISvlFHeuB62HXqgwKOjpJSOZJn4I2ZA2wGg45eabXyUkOMfdP8scZKEsGI0+R8FZR5SvqL2KHRESA4/WTFKOd+aJ/ojB0eKlD3dV6QuDnv3YeGtRXtCOCDKzQIBHQSACQUrHZ7x3bSX2D//ewheH24oBvSd1RwqYoPw3o7bS19L4TKo75h3B/t8RQOdNSVYN2OgyTKR1/MUl3bhz+U5ILzS2AZ7DE+DacEDhDpMVo=" Feb 23 23:17:26 volumio go-librespot[22125]: time="2026-02-23T23:17:26+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 23 23:17:26 volumio go-librespot[22125]: time="2026-02-23T23:17:26+07:00" level=debug msg="completed keyexchange" Feb 23 23:17:26 volumio go-librespot[22125]: time="2026-02-23T23:17:26+07:00" level=debug msg="completed challenge" Feb 23 23:17:26 volumio go-librespot[22125]: time="2026-02-23T23:17:26+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 23 23:17:26 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 23 23:17:26 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 23 23:17:28 volumio volumio[21804]: info: Initializing connection to go-librespot Websocket Feb 23 23:17:28 volumio volumio[21804]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 23 23:17:29 volumio volumio[21804]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 23 23:17:29 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Feb 23 23:17:29 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 23 23:17:29 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 23 23:17:29 volumio go-librespot[22135]: go-librespot daemon starting... Feb 23 23:17:29 volumio go-librespot[22136]: time="2026-02-23T23:17:29+07:00" level=info msg="running go-librespot 0.4.0" Feb 23 23:17:29 volumio go-librespot[22136]: time="2026-02-23T23:17:29+07:00" level=debug msg="app state loaded" Feb 23 23:17:29 volumio go-librespot[22136]: time="2026-02-23T23:17:29+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 23 23:17:30 volumio go-librespot[22136]: time="2026-02-23T23:17:30+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 23 23:17:30 volumio go-librespot[22136]: time="2026-02-23T23:17:30+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Feb 23 23:17:30 volumio go-librespot[22136]: time="2026-02-23T23:17:30+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Feb 23 23:17:30 volumio go-librespot[22136]: time="2026-02-23T23:17:30+07:00" level=info msg="zeroconf server listening on port 43449" Feb 23 23:17:30 volumio go-librespot[22136]: time="2026-02-23T23:17:30+07:00" level=debug msg="obtained new client token: AABGqwl1grLceWcKPYRWMImRodIgeuEkD3y+MDZmxGfdpnECheee9tYSv+m7jmtfL1tbDQJUiLfx075JUXbEkA9Xtu+2y9DYEZHb2044PL8gl0CPdtLs4y7NLoT/qKOsLtpfqQzmJvVHDCPXp8uhOogEo3pEYKqqMnnWELG4HHZJFXgRBGC3hBhAEJtzTne52/wkfDjaLvQAw9I+g422k526M+6XMLQCeRehsFnf90lUjW1M5UavHctUeQ==" Feb 23 23:17:30 volumio go-librespot[22136]: time="2026-02-23T23:17:30+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 23 23:17:30 volumio go-librespot[22136]: time="2026-02-23T23:17:30+07:00" level=debug msg="completed keyexchange" Feb 23 23:17:30 volumio go-librespot[22136]: time="2026-02-23T23:17:30+07:00" level=debug msg="completed challenge" Feb 23 23:17:30 volumio go-librespot[22136]: time="2026-02-23T23:17:30+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Feb 23 23:17:30 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 23 23:17:30 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 23 23:17:31 volumio volumio[21804]: info: Initializing connection to go-librespot Websocket Feb 23 23:17:32 volumio volumio[21804]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Feb 23 23:17:34 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Feb 23 23:17:34 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 23 23:17:34 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 23 23:17:34 volumio go-librespot[22158]: go-librespot daemon starting... Feb 23 23:17:34 volumio go-librespot[22159]: time="2026-02-23T23:17:34+07:00" level=info msg="running go-librespot 0.4.0" Feb 23 23:17:34 volumio go-librespot[22159]: time="2026-02-23T23:17:34+07:00" level=debug msg="app state loaded" Feb 23 23:17:34 volumio go-librespot[22159]: time="2026-02-23T23:17:34+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 23 23:17:34 volumio go-librespot[22159]: time="2026-02-23T23:17:34+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Feb 23 23:17:34 volumio go-librespot[22159]: time="2026-02-23T23:17:34+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 23 23:17:34 volumio go-librespot[22159]: time="2026-02-23T23:17:34+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 23 23:17:34 volumio go-librespot[22159]: time="2026-02-23T23:17:34+07:00" level=info msg="zeroconf server listening on port 33765" Feb 23 23:17:35 volumio volumio[21804]: info: Initializing connection to go-librespot Websocket Feb 23 23:17:35 volumio go-librespot[22159]: time="2026-02-23T23:17:35+07:00" level=debug msg="new websocket client" Feb 23 23:17:35 volumio volumio[21804]: info: Connection to go-librespot Websocket established Feb 23 23:17:35 volumio go-librespot[22159]: time="2026-02-23T23:17:35+07:00" level=debug msg="obtained new client token: AACjs1ErJDMRRRhbHutx9hD7l5VsvsWvdF8YeHNS4czzru/0HJQbnrQXc3r0XAHiw2bNU8+BnfLWOMNPsaJKaLpuS8Dtz/0hj1hxAKCV4z+qpP9LLktH6fK5shE8lvyYckw0jGckO/BmRQDPz+tM016VyABhvAEvYr93jyYx+x9d3vnkh6ZG34jzJvIdQu46kk3KXR/4xnsjlLXBxdvKfN4A9XjBVFVCWRGUAd6jZiX18R4RoBRLrLI=" Feb 23 23:17:35 volumio go-librespot[22159]: time="2026-02-23T23:17:35+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 23 23:17:35 volumio volumio[21804]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Feb 23 23:17:35 volumio volumio[21804]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Feb 23 23:17:35 volumio volumio[21804]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Feb 23 23:17:35 volumio volumio[21804]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Feb 23 23:17:35 volumio volumio[21804]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Feb 23 23:17:35 volumio volumio[21804]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Feb 23 23:17:35 volumio volumio[21804]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Feb 23 23:17:35 volumio volumio[21804]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Feb 23 23:17:35 volumio volumio[21804]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Feb 23 23:17:35 volumio volumio[21804]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Feb 23 23:17:35 volumio volumio[21804]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Feb 23 23:17:35 volumio volumio[21804]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Feb 23 23:17:35 volumio volumio[21804]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Feb 23 23:17:35 volumio volumio[21804]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Feb 23 23:17:35 volumio volumio[21804]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Feb 23 23:17:35 volumio volumio[21804]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Feb 23 23:17:35 volumio volumio[21804]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Feb 23 23:17:35 volumio volumio[21804]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Feb 23 23:17:35 volumio volumio[21804]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Feb 23 23:17:35 volumio volumio[21804]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Feb 23 23:17:35 volumio volumio[21804]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Feb 23 23:17:35 volumio volumio[21804]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Feb 23 23:17:35 volumio volumio[21804]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Feb 23 23:17:35 volumio volumio[21804]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Feb 23 23:17:35 volumio volumio[21804]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Feb 23 23:17:35 volumio volumio[21804]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Feb 23 23:17:35 volumio volumio[21804]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Feb 23 23:17:35 volumio volumio[21804]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Feb 23 23:17:35 volumio volumio[21804]: info: Adding plugin bluetooth to MyMusic Plugins Feb 23 23:17:35 volumio volumio[21804]: info: Adding plugin multiroom to MyMusic Plugins Feb 23 23:17:35 volumio volumio[21804]: info: Adding plugin metavolumio to MyMusic Plugins Feb 23 23:17:35 volumio volumio[21804]: info: Adding plugin cd_controller to MyMusic Plugins Feb 23 23:17:35 volumio volumio[21804]: info: Adding plugin qobuzconnect to MyMusic Plugins Feb 23 23:17:35 volumio volumio[21804]: info: Adding plugin smart_inputs to MyMusic Plugins Feb 23 23:17:35 volumio volumio[21804]: info: Adding plugin tidalconnect to MyMusic Plugins Feb 23 23:17:35 volumio go-librespot[22159]: time="2026-02-23T23:17:35+07:00" level=debug msg="completed keyexchange" Feb 23 23:17:35 volumio volumio[21804]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Feb 23 23:17:35 volumio go-librespot[22159]: time="2026-02-23T23:17:35+07:00" level=debug msg="completed challenge" Feb 23 23:17:35 volumio go-librespot[22159]: time="2026-02-23T23:17: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 23 23:17:35 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 23 23:17:35 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 23 23:17:37 volumio volumio[21804]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Feb 23 23:17:37 volumio volumio[21804]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Feb 23 23:17:37 volumio volumio[21804]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 23 23:17:37 volumio volumio[21804]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Feb 23 23:17:37 volumio volumio[21804]: info: Starting MyVolumio Remote Streaming Endpoints Feb 23 23:17:37 volumio volumio[21804]: info: MyVolumio login type: Token Feb 23 23:17:37 volumio volumio[21804]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Feb 23 23:17:37 volumio volumio[21804]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Feb 23 23:17:38 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Feb 23 23:17:38 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Feb 23 23:17:38 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Feb 23 23:17:38 volumio go-librespot[22168]: go-librespot daemon starting... Feb 23 23:17:38 volumio go-librespot[22169]: time="2026-02-23T23:17:38+07:00" level=info msg="running go-librespot 0.4.0" Feb 23 23:17:38 volumio go-librespot[22169]: time="2026-02-23T23:17:38+07:00" level=debug msg="app state loaded" Feb 23 23:17:38 volumio go-librespot[22169]: time="2026-02-23T23:17:38+07:00" level=info msg="api server listening on 127.0.0.1:9879" Feb 23 23:17:39 volumio volumio[21804]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Feb 23 23:17:39 volumio volumio[21804]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Feb 23 23:17:39 volumio volumio[21804]: info: Streaming services startup Feb 23 23:17:39 volumio volumio[21804]: info: Starting Streaming Daemon Feb 23 23:17:39 volumio sudo[22177]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Feb 23 23:17:39 volumio sudo[22177]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Feb 23 23:17:39 volumio volumio[21804]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Feb 23 23:17:39 volumio sudo[22177]: pam_unix(sudo:session): session closed for user root Feb 23 23:17:39 volumio go-librespot[22169]: time="2026-02-23T23:17:39+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Feb 23 23:17:39 volumio go-librespot[22169]: time="2026-02-23T23:17:39+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 23 23:17:39 volumio go-librespot[22169]: time="2026-02-23T23:17:39+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 23 23:17:39 volumio volumio[21804]: info: Getting Spotify volume Feb 23 23:17:39 volumio go-librespot[22169]: time="2026-02-23T23:17:39+07:00" level=info msg="zeroconf server listening on port 35213" Feb 23 23:17:39 volumio volumio[21804]: info: Connection to go-librespot Websocket closed Feb 23 23:17:39 volumio volumio[21804]: error: Cannot start Volumio Streaming Daemon Feb 23 23:17:39 volumio volumio[21804]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Feb 23 23:17:39 volumio volumio[21804]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Feb 23 23:17:39 volumio volumio[21804]: 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 23 23:17:39 volumio go-librespot[22169]: time="2026-02-23T23:17:39+07:00" level=debug msg="obtained new client token: AABfVz5vZB4ZYWN1wMZe6FTb/O8i0vvG1iiAHwRhGXGyjG2UjyNxA+LFrfQWU72o7lxnim11ElmJ9CD7taKQVpQfKUw7MGnXHRiQQ89qxCBTmfkfuxD+YRalu6opoglvxObKrCcD5tU7IwZC5vAhqbGHKMLsQQHWO6iuL/qB0m4lSg4Xa3MiuxKw7esbhRu7T0ZsXOpsC42IyVpUCEn9DrCykQD0uCiNGCpXymyYn5cI5T8f47+0bTPi3Q==" Feb 23 23:17:39 volumio volumio[21804]: info: CoreCommandRouter::volumioGetState Feb 23 23:17:39 volumio volumio[21804]: info: CorePlayQueue::getTrack 0 Feb 23 23:17:39 volumio volumio[21804]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Feb 23 23:17:39 volumio volumio[21804]: SPOTIFY: SPOTIFY VOLUME undefined Feb 23 23:17:39 volumio volumio[21804]: SPOTIFY: VOLUMIO VOLUME 100 Feb 23 23:17:39 volumio volumio[21804]: info: Aligning Spotify Volume to Volumio Volume Feb 23 23:17:39 volumio volumio[21804]: info: CoreCommandRouter::volumioGetState Feb 23 23:17:39 volumio volumio[21804]: info: CorePlayQueue::getTrack 0 Feb 23 23:17:39 volumio volumio[21804]: info: Setting Spotify Volume from Volumio: 100 Feb 23 23:17:39 volumio go-librespot[22169]: time="2026-02-23T23:17:39+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Feb 23 23:17:39 volumio go-librespot[22169]: time="2026-02-23T23:17:39+07:00" level=debug msg="completed keyexchange" Feb 23 23:17:39 volumio go-librespot[22169]: time="2026-02-23T23:17:39+07:00" level=debug msg="completed challenge" Feb 23 23:17:40 volumio go-librespot[22169]: time="2026-02-23T23:17: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 23 23:17:40 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Feb 23 23:17:40 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Feb 23 23:17:40 volumio volumio[21804]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 23 23:17:40 volumio volumio[21804]: Error: socket hang up Feb 23 23:17:40 volumio volumio[21804]: at connResetException (node:internal/errors:720:14) Feb 23 23:17:40 volumio volumio[21804]: at Socket.socketOnEnd (node:_http_client:519:23) Feb 23 23:17:40 volumio volumio[21804]: at Socket.emit (node:events:526:35) Feb 23 23:17:40 volumio volumio[21804]: at endReadableNT (node:internal/streams/readable:1376:12) Feb 23 23:17:40 volumio volumio[21804]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Feb 23 23:17:40 volumio volumio[21804]: code: 'ECONNRESET', Feb 23 23:17:40 volumio volumio[21804]: response: undefined Feb 23 23:17:40 volumio volumio[21804]: } Feb 23 23:17:40 volumio volumio[21804]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 23 23:17:41 volumio sudo[22198]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-02-23 23:16' Feb 23 23:17:41 volumio sudo[22198]: 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"