Jan 27 20:01:00 volumio volumio-remote-updater[628]: [2026-01-27 20:01:00] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Jan 27 20:01:00 volumio volumio-remote-updater[628]: [2026-01-27 20:01:00] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Jan 27 20:01:00 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 27 20:01:00 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 27 20:01:00 volumio systemd[1]: volumio.service: Consumed 58.531s CPU time. Jan 27 20:01:00 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 27 20:01:01 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 27 20:01:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 20:01:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 20:01:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 20:01:01 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 9053. Jan 27 20:01:01 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 27 20:01:01 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Jan 27 20:01:01 volumio systemd[1]: volumio.service: Consumed 58.531s CPU time. Jan 27 20:01:01 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Jan 27 20:01:01 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 27 20:01:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Jan 27 20:01:02 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 20:01:02 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 20:01:02 volumio go-librespot[14386]: go-librespot daemon starting... Jan 27 20:01:02 volumio go-librespot[14387]: time="2026-01-27T20:01:02+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 20:01:02 volumio go-librespot[14387]: time="2026-01-27T20:01:02+07:00" level=debug msg="app state loaded" Jan 27 20:01:02 volumio go-librespot[14387]: time="2026-01-27T20:01:02+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 20:01:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 20:01:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 20:01:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 20:01:03 volumio go-librespot[14387]: time="2026-01-27T20:01:03+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 20:01:03 volumio go-librespot[14387]: time="2026-01-27T20:01:03+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]" Jan 27 20:01:03 volumio go-librespot[14387]: time="2026-01-27T20:01:03+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]" Jan 27 20:01:03 volumio go-librespot[14387]: time="2026-01-27T20:01:03+07:00" level=info msg="zeroconf server listening on port 40201" Jan 27 20:01:03 volumio go-librespot[14387]: time="2026-01-27T20:01:03+07:00" level=debug msg="obtained new client token: AAD0wvWiWSSTUV4IMRXzDwYfh39qC3uWVJB3eExZCYvwPHT2d2nrhvJ2Iezseb45WpALhKlyzcZ/QFbDrx9I0L/TdwDOdX2plqWmURI/X/2gnGkaG//e5exg+kpT28g5Z8NGnTgHsVmVUDtvaCvQe+uS1EQOhFkTe2hCUQGs2ZZ5LSfnXBFAEALLQnEjR5tWCtmaUBwsvKyicOPAs0p1GuadAC7geu1MTxM2wiqmI6ISnARqgxe5O0WtzKc=" Jan 27 20:01:03 volumio go-librespot[14387]: time="2026-01-27T20:01:03+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 20:01:03 volumio go-librespot[14387]: time="2026-01-27T20:01:03+07:00" level=debug msg="completed keyexchange" Jan 27 20:01:03 volumio go-librespot[14387]: time="2026-01-27T20:01:03+07:00" level=debug msg="completed challenge" Jan 27 20:01:03 volumio go-librespot[14387]: time="2026-01-27T20:01:03+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 20:01:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 20:01:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 20:01:04 volumio volumio[14370]: info: ------------------------------------------- Jan 27 20:01:04 volumio volumio[14370]: info: ----- Volumio3 ---- Jan 27 20:01:04 volumio volumio[14370]: info: ------------------------------------------- Jan 27 20:01:04 volumio volumio[14370]: info: ----- System startup ---- Jan 27 20:01:04 volumio volumio[14370]: info: ------------------------------------------- Jan 27 20:01:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 20:01:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 20:01:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 20:01:05 volumio volumio-remote-updater[628]: [2026-01-27 20:01:05] [connect] Successful connection Jan 27 20:01:06 volumio volumio[14370]: info: MYVOLUMIO Environment detected Jan 27 20:01:06 volumio volumio[14370]: info: Plugin folders cleanup Jan 27 20:01:06 volumio volumio[14370]: info: Scanning into folder /volumio/app/plugins/ Jan 27 20:01:06 volumio volumio[14370]: info: Scanning category audio_interface Jan 27 20:01:06 volumio volumio[14370]: info: Scanning category miscellanea Jan 27 20:01:06 volumio volumio[14370]: info: Scanning category music_service Jan 27 20:01:06 volumio volumio[14370]: info: Scanning category plugins.json Jan 27 20:01:06 volumio volumio[14370]: info: Scanning category system_controller Jan 27 20:01:06 volumio volumio[14370]: info: Scanning category user_interface Jan 27 20:01:06 volumio volumio[14370]: info: Scanning into folder /data/plugins/ Jan 27 20:01:06 volumio volumio[14370]: info: Scanning category music_service Jan 27 20:01:06 volumio volumio[14370]: info: Plugin folders cleanup completed Jan 27 20:01:06 volumio volumio[14370]: info: ------------------------------------------- Jan 27 20:01:06 volumio volumio[14370]: info: ----- Core plugins startup ---- Jan 27 20:01:06 volumio volumio[14370]: info: ------------------------------------------- Jan 27 20:01:06 volumio volumio[14370]: info: Loading plugins from folder /volumio/app/plugins/ Jan 27 20:01:06 volumio volumio[14370]: info: Adding plugin upnp to MyMusic Plugins Jan 27 20:01:06 volumio volumio[14370]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 27 20:01:06 volumio volumio[14370]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 27 20:01:06 volumio volumio[14370]: info: Loading plugins from folder /data/plugins/ Jan 27 20:01:06 volumio volumio[14370]: info: Loading plugin "system"... Jan 27 20:01:06 volumio volumio[14370]: info: Loading plugin "appearance"... Jan 27 20:01:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Jan 27 20:01:06 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 20:01:07 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 20:01:07 volumio go-librespot[14406]: go-librespot daemon starting... Jan 27 20:01:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 20:01:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 20:01:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 20:01:07 volumio go-librespot[14407]: time="2026-01-27T20:01:07+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 20:01:07 volumio go-librespot[14407]: time="2026-01-27T20:01:07+07:00" level=debug msg="app state loaded" Jan 27 20:01:07 volumio go-librespot[14407]: time="2026-01-27T20:01:07+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 20:01:07 volumio go-librespot[14407]: time="2026-01-27T20:01:07+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 27 20:01:07 volumio go-librespot[14407]: time="2026-01-27T20:01:07+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]" Jan 27 20:01:07 volumio go-librespot[14407]: time="2026-01-27T20:01:07+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]" Jan 27 20:01:07 volumio go-librespot[14407]: time="2026-01-27T20:01:07+07:00" level=info msg="zeroconf server listening on port 45153" Jan 27 20:01:07 volumio go-librespot[14407]: time="2026-01-27T20:01:07+07:00" level=debug msg="obtained new client token: AACGMTgfwebgV2j9c/pOrnIayjU/ANottdy1lRhaTbus2ohMwPVDIXdh/Hw37AUnS2qbjQc7/gvGk1TII36Z90Byy0hDg04KOGrrs/FtGCkBXIWRQYvJXV9zKVgYdA/gsbQ4W4XkGtXz5uR6ZImic+dt4wV96k0oS2yGH0AA4c61lT+1DZrf115judAJ7MVc7PSXczrTlAIKvYShs4EvF40GhB8YcjIlH0eaToicOgw2nEbgOenoCWaLqrE=" Jan 27 20:01:08 volumio go-librespot[14407]: time="2026-01-27T20:01:08+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 20:01:08 volumio go-librespot[14407]: time="2026-01-27T20:01:08+07:00" level=debug msg="completed keyexchange" Jan 27 20:01:08 volumio go-librespot[14407]: time="2026-01-27T20:01:08+07:00" level=debug msg="completed challenge" Jan 27 20:01:08 volumio go-librespot[14407]: time="2026-01-27T20:01:08+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 20:01:08 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 20:01:08 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 20:01:08 volumio volumio[14370]: info: Loading plugin "network"... Jan 27 20:01:08 volumio volumio[14370]: info: Refreshing Cached IP Addresses Jan 27 20:01:08 volumio sudo[14416]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 27 20:01:08 volumio sudo[14416]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 20:01:08 volumio sudo[14418]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 27 20:01:08 volumio sudo[14418]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 20:01:08 volumio sudo[14416]: pam_unix(sudo:session): session closed for user root Jan 27 20:01:08 volumio volumio[14370]: info: Loading plugin "services"... Jan 27 20:01:08 volumio sudo[14418]: pam_unix(sudo:session): session closed for user root Jan 27 20:01:08 volumio volumio[14370]: info: Loading plugin "alsa_controller"... Jan 27 20:01:08 volumio sudo[14426]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 27 20:01:08 volumio sudo[14426]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 20:01:08 volumio volumio[14370]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 27 20:01:08 volumio volumio[14370]: info: Loading plugin "wizard"... Jan 27 20:01:08 volumio volumio[14370]: info: Loading plugin "networkfs"... Jan 27 20:01:08 volumio volumio[14370]: info: Starting Udev Watcher for removable devices Jan 27 20:01:08 volumio volumio[14370]: info: Ignoring mount for partition: boot Jan 27 20:01:08 volumio volumio[14370]: info: Ignoring mount for partition: volumio Jan 27 20:01:08 volumio volumio[14370]: info: Ignoring mount for partition: volumio_data Jan 27 20:01:08 volumio volumio[14370]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 27 20:01:08 volumio volumio[14370]: info: Loading plugin "volumio_command_line_client"... Jan 27 20:01:08 volumio volumio[14370]: info: Loading plugin "upnp"... Jan 27 20:01:08 volumio volumio[14370]: info: [1769518868980] Starting Upmpd Daemon Jan 27 20:01:08 volumio volumio[14370]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 27 20:01:08 volumio volumio[14370]: info: Loading plugin "my_music"... Jan 27 20:01:08 volumio volumio[14370]: info: Loading plugin "mpd"... Jan 27 20:01:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 20:01:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 20:01:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 20:01:09 volumio volumio[14370]: info: Loading plugin "upnp_browser"... Jan 27 20:01:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 20:01:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 20:01:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 20:01:11 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Jan 27 20:01:11 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 20:01:11 volumio sudo[14426]: pam_unix(sudo:session): session closed for user root Jan 27 20:01:11 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 20:01:11 volumio go-librespot[14452]: go-librespot daemon starting... Jan 27 20:01:11 volumio go-librespot[14453]: time="2026-01-27T20:01:11+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 20:01:11 volumio go-librespot[14453]: time="2026-01-27T20:01:11+07:00" level=debug msg="app state loaded" Jan 27 20:01:11 volumio go-librespot[14453]: time="2026-01-27T20:01:11+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 20:01:12 volumio go-librespot[14453]: time="2026-01-27T20:01:12+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 20:01:12 volumio go-librespot[14453]: time="2026-01-27T20:01:12+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 27 20:01:12 volumio go-librespot[14453]: time="2026-01-27T20:01:12+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 27 20:01:12 volumio go-librespot[14453]: time="2026-01-27T20:01:12+07:00" level=info msg="zeroconf server listening on port 34457" Jan 27 20:01:12 volumio go-librespot[14453]: time="2026-01-27T20:01:12+07:00" level=debug msg="obtained new client token: AAAW5kkHeYs4jRSBOCwSrDH9X8WDoU7zywZb1pbaAzWA51A5WKH8h4IywzzBkmVF64nxaUJRqcLjbLXO1GXx/7GEedcJqkCHWAUvsNoSPwWxKNT9Vb5DYpeiB79XtJBBlxmYsf82br1h0n16qpCvsElkbtx6FBef1ZDdiq+c+aXbHYsy+TEqjtBSJh0Wn/K7ZSIfujqwaqz5vHVQyMKbzY5sJGCEdNSRPHA6bk3d4Sqk6SgyrSqimNSq" Jan 27 20:01:12 volumio go-librespot[14453]: time="2026-01-27T20:01:12+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 20:01:12 volumio go-librespot[14453]: time="2026-01-27T20:01:12+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" Jan 27 20:01:12 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 20:01:12 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 20:01:12 volumio volumio[14370]: info: Starting UPNP Browser Jan 27 20:01:12 volumio volumio[14370]: info: Loading plugin "alarm-clock"... Jan 27 20:01:12 volumio volumio[14370]: info: Loading plugin "airplay_emulation"... Jan 27 20:01:12 volumio volumio[14370]: info: Starting Shairport Sync Jan 27 20:01:12 volumio volumio[14370]: info: Loading plugin "last_100"... Jan 27 20:01:12 volumio volumio[14370]: info: Loading plugin "webradio"... Jan 27 20:01:13 volumio volumio[14370]: info: Loading plugin "i2s_dacs"... Jan 27 20:01:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 20:01:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 20:01:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 20:01:13 volumio volumio[14370]: info: Loading plugin "volumiodiscovery"... Jan 27 20:01:13 volumio volumio[14370]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 27 20:01:13 volumio volumio[14370]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 27 20:01:13 volumio node[14370]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 27 20:01:13 volumio volumio[14370]: *** WARNING *** For more information see Jan 27 20:01:13 volumio volumio[14370]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 27 20:01:13 volumio volumio[14370]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 27 20:01:13 volumio volumio[14370]: *** WARNING *** For more information see Jan 27 20:01:13 volumio node[14370]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 27 20:01:13 volumio node[14370]: *** WARNING *** For more information see Jan 27 20:01:13 volumio node[14370]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 27 20:01:13 volumio node[14370]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 27 20:01:13 volumio node[14370]: *** WARNING *** For more information see Jan 27 20:01:13 volumio volumio[14370]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 27 20:01:13 volumio volumio[14370]: info: Discovery: Started advertising with name: Volumio Jan 27 20:01:13 volumio volumio[14370]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 27 20:01:13 volumio volumio[14370]: info: Loading plugin "spop"... Jan 27 20:01:15 volumio volumio[14370]: info: Loading plugin "ytcr"... Jan 27 20:01:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 20:01:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 20:01:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 20:01:15 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Jan 27 20:01:15 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 20:01:15 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 20:01:15 volumio go-librespot[14462]: go-librespot daemon starting... Jan 27 20:01:15 volumio go-librespot[14463]: time="2026-01-27T20:01:15+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 20:01:15 volumio go-librespot[14463]: time="2026-01-27T20:01:15+07:00" level=debug msg="app state loaded" Jan 27 20:01:15 volumio go-librespot[14463]: time="2026-01-27T20:01:15+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 20:01:16 volumio go-librespot[14463]: time="2026-01-27T20:01:16+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 20:01:16 volumio go-librespot[14463]: time="2026-01-27T20:01:16+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 27 20:01:16 volumio go-librespot[14463]: time="2026-01-27T20:01:16+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 27 20:01:16 volumio go-librespot[14463]: time="2026-01-27T20:01:16+07:00" level=info msg="zeroconf server listening on port 46047" Jan 27 20:01:16 volumio go-librespot[14463]: time="2026-01-27T20:01:16+07:00" level=debug msg="obtained new client token: AABHyZqdD2ayN963R1PI1zkmdgSPhso3Pn7DR5EOqvz6VpTWFnZ8nRYR88yqFwH1pRMWzbsWY6jZRdnlV0+y3QbNXakzPoPIdl9nNmPXEELD0F4uEHUnkHVRSPXcfsr1lZ6o6Gb0ObRNVHJO26z/FiuTZtNMfeBsU5SJ9pxbpWzKJA1DO5OsXAJuc6T1AZ5Hqk3TbddpNlHL3bR19hqvpLqW/2dEpzPsgiD00mu0sdvKDKHmoSm9MADI2RM=" Jan 27 20:01:16 volumio go-librespot[14463]: time="2026-01-27T20:01:16+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 20:01:16 volumio go-librespot[14463]: time="2026-01-27T20:01:16+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" Jan 27 20:01:16 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 20:01:16 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 20:01:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 20:01:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 20:01:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 20:01:17 volumio volumio[14370]: info: Loading plugin "ytmusic"... Jan 27 20:01:18 volumio volumio-remote-updater[628]: [2026-01-27 20:01:18] [connect] Successful connection Jan 27 20:01:18 volumio volumio[14370]: info: Loading plugin "outputs"... Jan 27 20:01:18 volumio volumio[14370]: info: Loading plugin "albumart"... Jan 27 20:01:18 volumio volumio[14370]: info: Plugin example_plugin is not enabled Jan 27 20:01:18 volumio volumio[14370]: info: Loading plugin "inputs"... Jan 27 20:01:18 volumio volumio[14370]: info: Loading plugin "updater_comm"... Jan 27 20:01:19 volumio volumio[14370]: info: Plugin mpdemulation is not enabled Jan 27 20:01:19 volumio volumio[14370]: info: Loading plugin "rest_api"... Jan 27 20:01:19 volumio volumio[14370]: info: Loading plugin "websocket"... Jan 27 20:01:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 20:01:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 20:01:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 20:01:19 volumio volumio[14370]: info: Starting Socket.io Server version 1.7.4 Jan 27 20:01:19 volumio volumio[14370]: info: Loading plugin "RoonBridge"... Jan 27 20:01:19 volumio volumio[14370]: info: Applying required configuration parameters for plugin RoonBridge Jan 27 20:01:19 volumio volumio[14370]: info: Loading i18n strings for locale en Jan 27 20:01:19 volumio volumio[14370]: Updating browse sources language Jan 27 20:01:19 volumio volumio[14370]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 20:01:19 volumio volumio[14483]: Forking 3 albumart workers Jan 27 20:01:19 volumio volumio[14370]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 27 20:01:19 volumio volumio[14370]: info: CoreCommandRouter::initPlayerControls Jan 27 20:01:19 volumio volumio[14370]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:01:19 volumio volumio[14370]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:01:19 volumio volumio[14370]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:01:19 volumio volumio[14370]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:01:19 volumio volumio[14370]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:01:19 volumio volumio[14370]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:01:19 volumio volumio[14370]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:01:19 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Jan 27 20:01:19 volumio volumio[14370]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:01:19 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 20:01:20 volumio volumio[14370]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 27 20:01:20 volumio volumio[14370]: Express server listening on port 3000 Jan 27 20:01:20 volumio volumio[14370]: [Metrics] WebUI: 16s 10.68ms Jan 27 20:01:20 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 20:01:20 volumio go-librespot[14513]: go-librespot daemon starting... Jan 27 20:01:20 volumio volumio[14370]: info: CoreStateMachine::resetVolumioState Jan 27 20:01:20 volumio volumio[14370]: info: CoreStateMachine::getcurrentVolume Jan 27 20:01:20 volumio volumio[14370]: info: CoreCommandRouter::volumioRetrievevolume Jan 27 20:01:20 volumio go-librespot[14525]: time="2026-01-27T20:01:20+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 20:01:20 volumio go-librespot[14525]: time="2026-01-27T20:01:20+07:00" level=debug msg="app state loaded" Jan 27 20:01:20 volumio go-librespot[14525]: time="2026-01-27T20:01:20+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 20:01:20 volumio sudo[14533]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 27 20:01:20 volumio sudo[14533]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 20:01:20 volumio sudo[14533]: pam_unix(sudo:session): session closed for user root Jan 27 20:01:20 volumio sudo[14537]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 27 20:01:20 volumio sudo[14537]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 20:01:20 volumio sudo[14537]: pam_unix(sudo:session): session closed for user root Jan 27 20:01:20 volumio volumio[14370]: info: Volumio Network Manager: Network status updated: 1 Jan 27 20:01:20 volumio go-librespot[14525]: time="2026-01-27T20:01:20+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 27 20:01:20 volumio go-librespot[14525]: time="2026-01-27T20:01:20+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443]" Jan 27 20:01:20 volumio go-librespot[14525]: time="2026-01-27T20:01:20+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]" Jan 27 20:01:20 volumio go-librespot[14525]: time="2026-01-27T20:01:20+07:00" level=info msg="zeroconf server listening on port 38673" Jan 27 20:01:20 volumio volumio[14370]: info: VolumeController:: Volume=100 Mute =false Jan 27 20:01:20 volumio volumio[14370]: info: CoreStateMachine::pushState Jan 27 20:01:20 volumio volumio[14370]: info: CorePlayQueue::getTrack 0 Jan 27 20:01:20 volumio volumio[14370]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 27 20:01:20 volumio volumio[14370]: info: CoreCommandRouter::volumioPushState Jan 27 20:01:20 volumio volumio[14370]: info: CoreStateMachine::updateTrackBlock Jan 27 20:01:20 volumio volumio[14370]: info: CorePlayQueue::getTrackBlock Jan 27 20:01:20 volumio volumio[14370]: info: CoreCommandRouter::volumioRetrievevolume Jan 27 20:01:20 volumio volumio-remote-updater[628]: [2026-01-27 20:01:20] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1769518878 101 Jan 27 20:01:21 volumio volumio[14370]: 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 Jan 27 20:01:21 volumio volumio[14370]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 20:01:21 volumio volumio[14370]: info: Reloading queue from file Jan 27 20:01:21 volumio go-librespot[14525]: time="2026-01-27T20:01:21+07:00" level=debug msg="obtained new client token: AACdZ276zm/YDaM0VvEykREDIuA2+zuUKslZV3aB14DkI8wmlxHrVD6mwIxksWzfE9ti7ehaGhVekJnez0cHc2FsxvfbukX3+rZNGlxkzEtPpAau9sA2VALxPSjhm2i9zZI8PV+pjUV1qQAgpE191LHfmVGn1oXdWjJ4FkhRVc9gmpQM1hq77AamDd3ccLCTDxM4qIV/p5OX8sZSFugNlEkH94Q/eevZLAt1HRVDJESepF3IuwIfq/iq" Jan 27 20:01:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 20:01:21 volumio volumio[14370]: info: CoreStateMachine::setRepeat null single undefined Jan 27 20:01:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 20:01:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 20:01:21 volumio volumio[14370]: info: CoreStateMachine::pushState Jan 27 20:01:21 volumio volumio[14370]: info: CorePlayQueue::getTrack 0 Jan 27 20:01:21 volumio volumio[14370]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 27 20:01:21 volumio volumio[14370]: info: CoreCommandRouter::volumioPushState Jan 27 20:01:21 volumio volumio[14370]: info: CoreStateMachine::setRandom null Jan 27 20:01:21 volumio volumio[14370]: info: CoreStateMachine::pushState Jan 27 20:01:21 volumio volumio[14370]: info: CorePlayQueue::getTrack 0 Jan 27 20:01:21 volumio volumio[14370]: info: CoreCommandRouter::volumioPushState Jan 27 20:01:21 volumio volumio[14370]: info: Setting Device type: Raspberry PI Jan 27 20:01:21 volumio go-librespot[14525]: time="2026-01-27T20:01:21+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 20:01:21 volumio volumio[14370]: info: Completed loading Core Plugins Jan 27 20:01:21 volumio volumio[14370]: info: Preparing to generate the ALSA configuration file Jan 27 20:01:21 volumio go-librespot[14525]: time="2026-01-27T20:01:21+07:00" level=debug msg="completed keyexchange" Jan 27 20:01:21 volumio go-librespot[14525]: time="2026-01-27T20:01:21+07:00" level=debug msg="completed challenge" Jan 27 20:01:21 volumio volumio[14370]: info: VolumeController:: Volume=100 Mute =false Jan 27 20:01:21 volumio volumio[14370]: info: CoreStateMachine::pushState Jan 27 20:01:21 volumio volumio[14370]: info: CorePlayQueue::getTrack 0 Jan 27 20:01:21 volumio volumio[14370]: info: CoreCommandRouter::volumioPushState Jan 27 20:01:21 volumio volumio[14370]: info: Asound.conf file unchanged, so no further update is needed Jan 27 20:01:21 volumio volumio[14370]: info: Output device has changed, restarting MPD Jan 27 20:01:21 volumio go-librespot[14525]: time="2026-01-27T20:01:21+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 20:01:21 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 20:01:21 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 20:01:21 volumio volumio[14370]: info: Output device has changed, restarting Shairport Sync Jan 27 20:01:21 volumio volumio[14370]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:01:21 volumio volumio[14370]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 20:01:21 volumio sudo[14552]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 27 20:01:21 volumio sudo[14552]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 20:01:21 volumio sudo[14554]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 27 20:01:21 volumio sudo[14554]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 20:01:21 volumio sudo[14556]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 27 20:01:21 volumio sudo[14554]: pam_unix(sudo:session): session closed for user root Jan 27 20:01:21 volumio sudo[14556]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 20:01:21 volumio volumio[14370]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 27 20:01:21 volumio volumio[14370]: info: ___________ START PLUGINS ___________ Jan 27 20:01:21 volumio volumio[14370]: info: ControllerMpd::onStart: Initializing MPD Jan 27 20:01:21 volumio volumio[14370]: info: Creating MPD Configuration file Jan 27 20:01:21 volumio sudo[14552]: pam_unix(sudo:session): session closed for user root Jan 27 20:01:21 volumio volumio[14370]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 27 20:01:21 volumio volumio[14370]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 20:01:21 volumio volumio[14370]: info: [1769518881696] CoreMusicLibrary::Adding element Media Servers Jan 27 20:01:21 volumio volumio[14370]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 20:01:21 volumio sudo[14566]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 27 20:01:21 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 27 20:01:21 volumio sudo[14566]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 20:01:21 volumio sudo[14566]: pam_unix(sudo:session): session closed for user root Jan 27 20:01:21 volumio sudo[14568]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 27 20:01:21 volumio sudo[14568]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 20:01:21 volumio volumio[14370]: info: UPNP Browser: Client initialized successfully Jan 27 20:01:21 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 27 20:01:21 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 27 20:01:21 volumio systemd[1]: mpd.service: Consumed 7.196s CPU time. Jan 27 20:01:21 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 27 20:01:21 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 27 20:01:21 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 27 20:01:21 volumio volumio[14370]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:01:21 volumio volumio[14370]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 20:01:21 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 27 20:01:21 volumio volumio[14370]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 27 20:01:21 volumio volumio[14370]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:01:21 volumio volumio[14370]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 20:01:21 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 27 20:01:22 volumio volumio[14370]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 27 20:01:22 volumio volumio[14370]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 20:01:22 volumio volumio[14370]: info: [1769518882055] CoreMusicLibrary::Adding element Last_100 Jan 27 20:01:22 volumio volumio[14370]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 20:01:22 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 27 20:01:22 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 27 20:01:22 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 27 20:01:22 volumio volumio[14370]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 20:01:22 volumio volumio[14370]: info: [1769518882092] CoreMusicLibrary::Adding element Webradio Jan 27 20:01:22 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 27 20:01:22 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 27 20:01:22 volumio volumio[14370]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 20:01:22 volumio volumio[14370]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 27 20:01:22 volumio volumio[14370]: info: Initializing BBC Radios Jan 27 20:01:22 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 27 20:01:22 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 27 20:01:22 volumio volumio[14370]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 27 20:01:22 volumio volumio[14370]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 20:01:22 volumio volumio[14370]: info: Creating Spotify config file Jan 27 20:01:22 volumio volumio[14370]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:01:22 volumio sudo[14590]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 27 20:01:22 volumio sudo[14590]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 27 20:01:22 volumio sudo[14590]: pam_unix(sudo:session): session closed for user root Jan 27 20:01:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 20:01:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 20:01:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 20:01:23 volumio volumio[14496]: Starting albumart workers Jan 27 20:01:23 volumio volumio[14370]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 20:01:23 volumio volumio[14370]: info: [1769518883442] CoreMusicLibrary::Adding element YouTube Music Jan 27 20:01:23 volumio volumio[14370]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 20:01:23 volumio volumio[14370]: Cannot find translation for source YouTube Music Jan 27 20:01:23 volumio volumio[14495]: Starting albumart workers Jan 27 20:01:23 volumio volumio[14494]: Starting albumart workers Jan 27 20:01:23 volumio volumio[14370]: info: Volumio Calling Home Jan 27 20:01:23 volumio sudo[14599]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Jan 27 20:01:23 volumio sudo[14599]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 20:01:23 volumio sudo[14599]: pam_unix(sudo:session): session closed for user root Jan 27 20:01:24 volumio volumio[14370]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Jan 27 20:01:24 volumio volumio[14370]: info: Discovery: Found device Volumio Jan 27 20:01:24 volumio volumio[14370]: info: CoreCommandRouter::volumioGetState Jan 27 20:01:24 volumio volumio[14370]: info: CorePlayQueue::getTrack 0 Jan 27 20:01:24 volumio volumio[14370]: info: MPD Permissions set Jan 27 20:01:24 volumio volumio[14370]: info: MPD Permissions set Jan 27 20:01:24 volumio volumio[14370]: info: Upmpdcli Daemon Started Jan 27 20:01:24 volumio volumio[14370]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Jan 27 20:01:24 volumio volumio[14370]: info: Discovery: Found device Volumio Jan 27 20:01:24 volumio volumio[14370]: info: CoreCommandRouter::volumioGetState Jan 27 20:01:24 volumio volumio[14370]: info: CorePlayQueue::getTrack 0 Jan 27 20:01:24 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Jan 27 20:01:24 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 20:01:24 volumio volumio[14370]: info: Volumio called home Jan 27 20:01:24 volumio volumio[14370]: info: Spotify config file written Jan 27 20:01:24 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 20:01:24 volumio go-librespot[14604]: go-librespot daemon starting... Jan 27 20:01:24 volumio go-librespot[14606]: time="2026-01-27T20:01:24+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 20:01:24 volumio go-librespot[14606]: time="2026-01-27T20:01:24+07:00" level=debug msg="app state loaded" Jan 27 20:01:24 volumio go-librespot[14606]: time="2026-01-27T20:01:24+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 20:01:24 volumio sudo[14607]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 27 20:01:24 volumio sudo[14607]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 20:01:24 volumio systemd[1]: Stopping go-librespot-daemon.service - go-librespot Daemon... Jan 27 20:01:24 volumio systemd[1]: go-librespot-daemon.service: Deactivated successfully. Jan 27 20:01:24 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 20:01:24 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 20:01:24 volumio volumio[14370]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Jan 27 20:01:24 volumio go-librespot[14615]: go-librespot daemon starting... Jan 27 20:01:24 volumio sudo[14607]: pam_unix(sudo:session): session closed for user root Jan 27 20:01:25 volumio volumio[14370]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:01:25 volumio volumio[14370]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:01:25 volumio volumio[14370]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:01:25 volumio volumio[14370]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:01:25 volumio volumio[14370]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:01:25 volumio volumio[14370]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:01:25 volumio volumio[14370]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:01:25 volumio volumio[14370]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:01:25 volumio go-librespot[14616]: time="2026-01-27T20:01:25+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 20:01:25 volumio go-librespot[14616]: time="2026-01-27T20:01:25+07:00" level=debug msg="app state loaded" Jan 27 20:01:25 volumio go-librespot[14616]: time="2026-01-27T20:01:25+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 20:01:25 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 20:01:25 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 20:01:25 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 20:01:25 volumio volumio[14370]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 20:01:25 volumio volumio[14370]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:01:25 volumio volumio[14370]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:01:25 volumio volumio[14370]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:01:25 volumio volumio[14370]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:01:25 volumio volumio[14370]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:01:25 volumio volumio[14370]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:01:25 volumio volumio[14370]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:01:25 volumio volumio[14370]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:01:25 volumio volumio[14370]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:01:25 volumio volumio[14370]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 20:01:25 volumio volumio[14370]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:01:25 volumio volumio[14370]: info: No need to fix Spotify hosts Jan 27 20:01:25 volumio go-librespot[14616]: time="2026-01-27T20:01: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-gew1.spotify.com:80]" Jan 27 20:01:25 volumio go-librespot[14616]: time="2026-01-27T20:01:25+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]" Jan 27 20:01:25 volumio go-librespot[14616]: time="2026-01-27T20:01:25+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]" Jan 27 20:01:25 volumio go-librespot[14616]: time="2026-01-27T20:01:25+07:00" level=info msg="zeroconf server listening on port 41497" Jan 27 20:01:26 volumio go-librespot[14616]: time="2026-01-27T20:01:26+07:00" level=debug msg="obtained new client token: AADyaduVCsu4Tmrn9hvhh0OtyUN2dtzZGbRpoelBC6ndUWPL95HkgJb4kulTv8t68G9aleQdd/5mO4FG6Hh03i8PW+fk9Y4t1kLWbGwBa35nKrNfmKBZET051thAOzseGFDzPf2HzkfzZyrWfv8+mPHSAvFkLpFB5tMQI26M4LFi9VK3nEZqxIz+SZsiiLYZQteK7SXeEJALEafruVJ98RGY5hE1E/dGxXlbF5gqU20z2U+mgKrPm3jN" Jan 27 20:01:26 volumio volumio[14370]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 27 20:01:26 volumio volumio[14370]: SPOTIFY: BQDrygzyZo2PNpVq34DlZs0jwQ1WCjrf7mDIFGHGGdHXHZ8rw6PSWEZbkixmdnVDiqhSwa0hGgW4xmdo18sRWcS25T3P5-N4TH_hUeYqQqeOSYx4xfgN6WN0ryNhpA9m8KAZryEVbUnq_PKqI_moJLm6F9ZV-VU1TQ8uRlJanoxVSKVrW3HJQqgexgAgKdJHnDuw6K39RHchaTFDXLd6cqbakaSBCDY8EwhnA2dr4H8SguL3Kr6X9dGhL4glRCbhjR2tzVVOdgz6RfugwfYilWLXDfH4ULxs2s6guoENKIteSIICy8MUPH9B Jan 27 20:01:26 volumio volumio[14370]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 27 20:01:26 volumio volumio[14370]: info: New Spotify access token = BQDrygzyZo2PNpVq34DlZs0jwQ1WCjrf7mDIFGHGGdHXHZ8rw6PSWEZbkixmdnVDiqhSwa0hGgW4xmdo18sRWcS25T3P5-N4TH_hUeYqQqeOSYx4xfgN6WN0ryNhpA9m8KAZryEVbUnq_PKqI_moJLm6F9ZV-VU1TQ8uRlJanoxVSKVrW3HJQqgexgAgKdJHnDuw6K39RHchaTFDXLd6cqbakaSBCDY8EwhnA2dr4H8SguL3Kr6X9dGhL4glRCbhjR2tzVVOdgz6RfugwfYilWLXDfH4ULxs2s6guoENKIteSIICy8MUPH9B Jan 27 20:01:26 volumio volumio[14370]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 27 20:01:26 volumio go-librespot[14616]: time="2026-01-27T20:01:26+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 20:01:26 volumio go-librespot[14616]: time="2026-01-27T20:01:26+07:00" level=debug msg="completed keyexchange" Jan 27 20:01:26 volumio go-librespot[14616]: time="2026-01-27T20:01:26+07:00" level=debug msg="completed challenge" Jan 27 20:01:26 volumio volumio[14370]: info: Starting Shairport Sync Jan 27 20:01:26 volumio go-librespot[14616]: time="2026-01-27T20:01: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 " Jan 27 20:01:26 volumio volumio[14370]: info: Starting Shairport Sync Jan 27 20:01:26 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 20:01:26 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 20:01:26 volumio volumio[14370]: info: Starting Shairport Sync Jan 27 20:01:26 volumio sudo[14654]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 27 20:01:26 volumio sudo[14654]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 20:01:26 volumio sudo[14656]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 27 20:01:26 volumio sudo[14656]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 20:01:26 volumio sudo[14658]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 27 20:01:26 volumio sudo[14658]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 20:01:26 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 27 20:01:26 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 27 20:01:26 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 27 20:01:26 volumio systemd[1]: shairport-sync.service: Consumed 2.395s CPU time. Jan 27 20:01:26 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 27 20:01:26 volumio sudo[14656]: pam_unix(sudo:session): session closed for user root Jan 27 20:01:26 volumio sudo[14658]: pam_unix(sudo:session): session closed for user root Jan 27 20:01:26 volumio sudo[14654]: pam_unix(sudo:session): session closed for user root Jan 27 20:01:26 volumio volumio[14370]: info: Shairport-Sync Started Jan 27 20:01:26 volumio volumio[14370]: Error adding Membership: Error: addMembership EINVAL Jan 27 20:01:26 volumio volumio[14370]: info: Shairport-Sync Started Jan 27 20:01:26 volumio volumio[14370]: info: CoreCommandRouter::volumioGetState Jan 27 20:01:26 volumio volumio[14370]: info: CorePlayQueue::getTrack 0 Jan 27 20:01:26 volumio volumio[14370]: info: Shairport-Sync Started Jan 27 20:01:27 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 20:01:27 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 20:01:27 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 20:01:27 volumio volumio[14370]: 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"} Jan 27 20:01:27 volumio volumio[14370]: info: Spotify Successfully logged in Jan 27 20:01:27 volumio volumio[14370]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 20:01:27 volumio volumio[14370]: info: [1769518887148] CoreMusicLibrary::Adding element Spotify Jan 27 20:01:27 volumio volumio[14370]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 20:01:27 volumio volumio[14370]: Cannot find translation for source YouTube Music Jan 27 20:01:27 volumio volumio[14370]: Cannot find translation for source Spotify Jan 27 20:01:27 volumio volumio[14370]: info: [yt-cast-receiver] DIAL server listening on port 8098 Jan 27 20:01:27 volumio volumio[14370]: info: CoreCommandRouter::volumioRetrievevolume Jan 27 20:01:28 volumio volumio[14370]: info: VolumeController:: Volume=100 Mute =false Jan 27 20:01:28 volumio volumio[14370]: info: CoreCommandRouter::volumioGetState Jan 27 20:01:28 volumio volumio[14370]: info: CorePlayQueue::getTrack 0 Jan 27 20:01:28 volumio volumio[14370]: info: CoreStateMachine::pushState Jan 27 20:01:28 volumio volumio[14370]: info: CorePlayQueue::getTrack 0 Jan 27 20:01:28 volumio volumio[14370]: info: CoreCommandRouter::volumioPushState Jan 27 20:01:28 volumio volumio[14370]: info: go-librespot daemon successfully initialized Jan 27 20:01:29 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 20:01:29 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 20:01:29 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 20:01:29 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 1. Jan 27 20:01:29 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 20:01:29 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 20:01:29 volumio go-librespot[14694]: go-librespot daemon starting... Jan 27 20:01:29 volumio go-librespot[14695]: time="2026-01-27T20:01:29+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 20:01:29 volumio go-librespot[14695]: time="2026-01-27T20:01:29+07:00" level=debug msg="app state loaded" Jan 27 20:01:29 volumio go-librespot[14695]: time="2026-01-27T20:01:29+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 20:01:29 volumio mpd[14597]: 2026-01-27T20:01:29 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 27 20:01:29 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 27 20:01:29 volumio sudo[14556]: pam_unix(sudo:session): session closed for user root Jan 27 20:01:29 volumio sudo[14568]: pam_unix(sudo:session): session closed for user root Jan 27 20:01:29 volumio volumio[14370]: error: MPD error: The expression evaluated to a falsy value: Jan 27 20:01:29 volumio volumio[14370]: assert.ok(self.idling) Jan 27 20:01:29 volumio volumio[14370]: error: The expression evaluated to a falsy value: Jan 27 20:01:29 volumio volumio[14370]: assert.ok(self.idling) Jan 27 20:01:30 volumio volumio[14370]: info: MPD running with PID14597 Jan 27 20:01:30 volumio volumio[14370]: ,establishing connection Jan 27 20:01:30 volumio volumio[14370]: error: updateQueue error: null Jan 27 20:01:30 volumio volumio[14370]: info: Completed starting Core Plugins Jan 27 20:01:30 volumio volumio[14370]: info: ------------------------------------------- Jan 27 20:01:30 volumio volumio[14370]: info: ----- MyVolumio plugins startup ---- Jan 27 20:01:30 volumio volumio[14370]: info: ------------------------------------------- Jan 27 20:01:30 volumio volumio[14370]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 27 20:01:30 volumio volumio[14370]: error: updateQueue error: null Jan 27 20:01:30 volumio go-librespot[14695]: time="2026-01-27T20:01: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]" Jan 27 20:01:30 volumio go-librespot[14695]: time="2026-01-27T20:01: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]" Jan 27 20:01:30 volumio go-librespot[14695]: time="2026-01-27T20:01: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]" Jan 27 20:01:30 volumio go-librespot[14695]: time="2026-01-27T20:01:30+07:00" level=info msg="zeroconf server listening on port 43471" Jan 27 20:01:30 volumio go-librespot[14695]: time="2026-01-27T20:01:30+07:00" level=debug msg="obtained new client token: AACoe9b3sZpYoAi5jtZGjtAaCECVQLzeto7+xQQiCFAqXOmB4mE2AK19vOB4uqh3jcwhMJxlp8imReUIFNmz13oJGSMhsKFbIGAhbE/oQaf/rTh+hFb+ceANLwVivHG1qqtU0TdQlpB0PH0JkwXQFG2BcUudm77L2UIWkTG7Z+xuovMhOPkjgwcnGPENPGgKFgqFVjkk8QtvMkoa9Mp+FfbEJsmdd/Xb2kNepCrtkMxV3VuH+Vfnbxb5y9M=" Jan 27 20:01:30 volumio go-librespot[14695]: time="2026-01-27T20:01:30+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" Jan 27 20:01:30 volumio go-librespot[14695]: time="2026-01-27T20:01:30+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 27 20:01:30 volumio go-librespot[14695]: time="2026-01-27T20:01:30+07:00" level=debug msg="completed keyexchange" Jan 27 20:01:30 volumio go-librespot[14695]: time="2026-01-27T20:01:30+07:00" level=debug msg="completed challenge" Jan 27 20:01:30 volumio go-librespot[14695]: time="2026-01-27T20:01: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 " Jan 27 20:01:30 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 20:01:30 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 20:01:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 20:01:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 20:01:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 20:01:31 volumio volumio[14370]: info: Initializing connection to go-librespot Websocket Jan 27 20:01:32 volumio volumio[14370]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 27 20:01:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 20:01:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 20:01:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 20:01:33 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Jan 27 20:01:33 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 20:01:33 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 20:01:33 volumio go-librespot[14708]: go-librespot daemon starting... Jan 27 20:01:33 volumio go-librespot[14709]: time="2026-01-27T20:01:33+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 20:01:33 volumio go-librespot[14709]: time="2026-01-27T20:01:33+07:00" level=debug msg="app state loaded" Jan 27 20:01:33 volumio go-librespot[14709]: time="2026-01-27T20:01:33+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 20:01:34 volumio go-librespot[14709]: time="2026-01-27T20:01: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-gew4.spotify.com:80]" Jan 27 20:01:34 volumio go-librespot[14709]: time="2026-01-27T20:01:34+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]" Jan 27 20:01:34 volumio go-librespot[14709]: time="2026-01-27T20:01:34+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]" Jan 27 20:01:34 volumio go-librespot[14709]: time="2026-01-27T20:01:34+07:00" level=info msg="zeroconf server listening on port 41981" Jan 27 20:01:34 volumio go-librespot[14709]: time="2026-01-27T20:01:34+07:00" level=debug msg="obtained new client token: AADTnEOiJK0o0HdZcLct3COZPrA+LtWJxwSIACtC5nP5Ieug8QNx9/YebK0aOKcfTLck5HMBN+5eadtxorcfTnzxJYQ0SWncg4+9Rn94OwBIFHqqGiDdpR9/iY+dl/2Q7eTSK0CkmeqHitYAxaCNJcuw4+PSfz7CvsExMJcwD8eX2QXskH6PT6/eUWQ8apzTP1tOLBFh2QETOizLxsAhK3nMJIOoqqXXwsRm1tj7MGVq7QuUCS4rKyB0Z0Q=" Jan 27 20:01:34 volumio go-librespot[14709]: time="2026-01-27T20:01:34+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 20:01:34 volumio go-librespot[14709]: time="2026-01-27T20:01:34+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" Jan 27 20:01:34 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 20:01:34 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 20:01:34 volumio volumio[14370]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 27 20:01:35 volumio volumio[14370]: info: Initializing connection to go-librespot Websocket Jan 27 20:01:35 volumio volumio[14370]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 27 20:01:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 20:01:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 20:01:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 20:01:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 20:01:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 20:01:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 20:01:37 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Jan 27 20:01:37 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 20:01:38 volumio volumio[14370]: info: Initializing connection to go-librespot Websocket Jan 27 20:01:38 volumio volumio[14370]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 27 20:01:38 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 20:01:38 volumio go-librespot[14718]: go-librespot daemon starting... Jan 27 20:01:38 volumio go-librespot[14719]: time="2026-01-27T20:01:38+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 20:01:38 volumio go-librespot[14719]: time="2026-01-27T20:01:38+07:00" level=debug msg="app state loaded" Jan 27 20:01:38 volumio go-librespot[14719]: time="2026-01-27T20:01:38+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 20:01:38 volumio go-librespot[14719]: time="2026-01-27T20:01:38+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]" Jan 27 20:01:38 volumio go-librespot[14719]: time="2026-01-27T20:01:38+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]" Jan 27 20:01:38 volumio go-librespot[14719]: time="2026-01-27T20:01:38+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]" Jan 27 20:01:38 volumio go-librespot[14719]: time="2026-01-27T20:01:38+07:00" level=info msg="zeroconf server listening on port 41191" Jan 27 20:01:38 volumio go-librespot[14719]: time="2026-01-27T20:01:38+07:00" level=debug msg="obtained new client token: AADYymWUUTWLsKX+hiVs0aQjl+kYfT1c2c9OrgIkMaH4ACh6T82/ugYYzydwz//ruZtwERGNf9ksy+Y9ItSf2dzUITfFFByFQ+PPT7J3U9620B2WDEWpwmCIZHViBaIhMHswH39Mp2HilrG8RZmGs866NrYdbNIMy5l1wYhF8ofiZi6nv8xx0Gk+1J+QChHlJLDT8h4a0ornvCFxbz6vi78MSlMfGDCHidqOgaNU445lVN3HS59AIL/Cqxk=" Jan 27 20:01:38 volumio volumio[14370]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 27 20:01:38 volumio volumio[14370]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 27 20:01:38 volumio volumio[14370]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 27 20:01:38 volumio volumio[14370]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jan 27 20:01:38 volumio volumio[14370]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 27 20:01:38 volumio volumio[14370]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 27 20:01:38 volumio volumio[14370]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 27 20:01:38 volumio volumio[14370]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 27 20:01:38 volumio go-librespot[14719]: time="2026-01-27T20:01:38+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 20:01:38 volumio volumio[14370]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 27 20:01:38 volumio volumio[14370]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 27 20:01:38 volumio volumio[14370]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jan 27 20:01:38 volumio volumio[14370]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 27 20:01:38 volumio volumio[14370]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 27 20:01:38 volumio volumio[14370]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 27 20:01:38 volumio volumio[14370]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jan 27 20:01:38 volumio volumio[14370]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 27 20:01:38 volumio volumio[14370]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 27 20:01:38 volumio volumio[14370]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 27 20:01:38 volumio volumio[14370]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 27 20:01:38 volumio volumio[14370]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 27 20:01:38 volumio volumio[14370]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 27 20:01:38 volumio volumio[14370]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jan 27 20:01:38 volumio volumio[14370]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 27 20:01:38 volumio volumio[14370]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jan 27 20:01:38 volumio volumio[14370]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 27 20:01:38 volumio volumio[14370]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 27 20:01:38 volumio volumio[14370]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 27 20:01:38 volumio volumio[14370]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 27 20:01:38 volumio volumio[14370]: info: Adding plugin bluetooth to MyMusic Plugins Jan 27 20:01:38 volumio volumio[14370]: info: Adding plugin multiroom to MyMusic Plugins Jan 27 20:01:38 volumio volumio[14370]: info: Adding plugin metavolumio to MyMusic Plugins Jan 27 20:01:38 volumio volumio[14370]: info: Adding plugin cd_controller to MyMusic Plugins Jan 27 20:01:38 volumio volumio[14370]: info: Adding plugin qobuzconnect to MyMusic Plugins Jan 27 20:01:38 volumio volumio[14370]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 27 20:01:38 volumio volumio[14370]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 27 20:01:38 volumio volumio[14370]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 27 20:01:39 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 20:01:39 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 20:01:39 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 20:01:39 volumio go-librespot[14719]: time="2026-01-27T20:01:39+07:00" level=debug msg="completed keyexchange" Jan 27 20:01:39 volumio go-librespot[14719]: time="2026-01-27T20:01:39+07:00" level=debug msg="completed challenge" Jan 27 20:01:39 volumio go-librespot[14719]: time="2026-01-27T20:01:39+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 " Jan 27 20:01:39 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 20:01:39 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 20:01:40 volumio volumio[14370]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 27 20:01:40 volumio volumio[14370]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 27 20:01:40 volumio volumio[14370]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 20:01:40 volumio volumio[14370]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 20:01:40 volumio volumio[14370]: info: Starting MyVolumio Remote Streaming Endpoints Jan 27 20:01:40 volumio volumio[14370]: info: MyVolumio login type: Token Jan 27 20:01:40 volumio volumio[14370]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 27 20:01:40 volumio volumio[14370]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 27 20:01:41 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 20:01:41 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 20:01:41 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 20:01:42 volumio volumio[14370]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 27 20:01:42 volumio volumio[14370]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 27 20:01:42 volumio volumio[14370]: info: Streaming services startup Jan 27 20:01:42 volumio volumio[14370]: info: Starting Streaming Daemon Jan 27 20:01:42 volumio sudo[14741]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 27 20:01:42 volumio sudo[14741]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 20:01:42 volumio volumio[14370]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 27 20:01:42 volumio sudo[14741]: pam_unix(sudo:session): session closed for user root Jan 27 20:01:42 volumio volumio[14370]: info: Initializing connection to go-librespot Websocket Jan 27 20:01:42 volumio volumio[14370]: error: Cannot start Volumio Streaming Daemon Jan 27 20:01:42 volumio volumio[14370]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 27 20:01:42 volumio volumio[14370]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 27 20:01:42 volumio volumio[14370]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 27 20:01:42 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Jan 27 20:01:42 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 20:01:43 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 20:01:43 volumio go-librespot[14749]: go-librespot daemon starting... Jan 27 20:01:43 volumio go-librespot[14750]: time="2026-01-27T20:01:43+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 20:01:43 volumio go-librespot[14750]: time="2026-01-27T20:01:43+07:00" level=debug msg="app state loaded" Jan 27 20:01:43 volumio go-librespot[14750]: time="2026-01-27T20:01:43+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 20:01:43 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 20:01:43 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 20:01:43 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 20:01:43 volumio go-librespot[14750]: time="2026-01-27T20:01:43+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 27 20:01:43 volumio go-librespot[14750]: time="2026-01-27T20:01:43+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]" Jan 27 20:01:43 volumio go-librespot[14750]: time="2026-01-27T20:01:43+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]" Jan 27 20:01:43 volumio go-librespot[14750]: time="2026-01-27T20:01:43+07:00" level=info msg="zeroconf server listening on port 41977" Jan 27 20:01:43 volumio volumio[14370]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Jan 27 20:01:43 volumio go-librespot[14750]: time="2026-01-27T20:01:43+07:00" level=debug msg="obtained new client token: AACBI7Q7s2LkuSyn91tIjYBFEwA+v15sKBEAiwciWHwu3fBWdOz7oH9HRrajOp1s35Oqpp+A7eG2YBo5JvR6L5Mu0/KdsPL0A92Xdb8pMfsxNaQC4sScG8x6belkcW5oykCneQYsROy8H19gGOJgHoGXRBdmv3bivzBBDnq/GXpTILdUpqNi0rqH96yXjsZJpyRPG9gB4ZwsudkVN/eZyDoBylFqO64xyPazS6YqhFutIKkxK1s1O1vfVXA=" Jan 27 20:01:43 volumio go-librespot[14750]: time="2026-01-27T20:01:43+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 20:01:44 volumio go-librespot[14750]: time="2026-01-27T20:01:44+07:00" level=debug msg="completed keyexchange" Jan 27 20:01:44 volumio go-librespot[14750]: time="2026-01-27T20:01:44+07:00" level=debug msg="completed challenge" Jan 27 20:01:44 volumio go-librespot[14750]: time="2026-01-27T20:01:44+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 20:01:44 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 20:01:44 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 20:01:44 volumio volumio[14370]: info: MyVolumio token set successfully Jan 27 20:01:44 volumio volumio[14370]: info: MYVOLUMIO: Adding device Jan 27 20:01:44 volumio volumio[14370]: info: MYVOLUMIO: Evaluating Server Jan 27 20:01:45 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 20:01:45 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 20:01:45 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 20:01:45 volumio volumio[14370]: info: MyVolumio status changed Jan 27 20:01:45 volumio volumio[14370]: info: Streaming services startup Jan 27 20:01:45 volumio volumio[14370]: info: Starting Streaming Daemon Jan 27 20:01:45 volumio volumio[14370]: info: Removing browser output: myVolumio user plan is not superstar Jan 27 20:01:45 volumio volumio[14370]: info: Removing audio output: Jan 27 20:01:45 volumio volumio[14370]: info: Stoppping Tunnel 1 Jan 27 20:01:45 volumio sudo[14778]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 27 20:01:45 volumio sudo[14778]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 20:01:45 volumio sudo[14778]: pam_unix(sudo:session): session closed for user root Jan 27 20:01:45 volumio sudo[14782]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Jan 27 20:01:45 volumio volumio[14370]: error: Cannot start Volumio Streaming Daemon Jan 27 20:01:45 volumio volumio[14370]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 27 20:01:45 volumio volumio[14370]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 27 20:01:45 volumio sudo[14782]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 20:01:45 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 27 20:01:45 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 27 20:01:45 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 27 20:01:45 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 27 20:01:45 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 27 20:01:45 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 27 20:01:45 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 27 20:01:45 volumio systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Jan 27 20:01:45 volumio sudo[14782]: pam_unix(sudo:session): session closed for user root Jan 27 20:01:45 volumio volumio[14370]: info: Remote SSH Stopped Jan 27 20:01:45 volumio volumio[14370]: info: Setting Geolocation for MyVolumio to as1 Jan 27 20:01:45 volumio volumio[14370]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 20:01:45 volumio volumio[14370]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 20:01:45 volumio volumio[14370]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 20:01:45 volumio volumio[14370]: info: Initializing connection to go-librespot Websocket Jan 27 20:01:45 volumio volumio[14370]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 27 20:01:46 volumio volumio[14370]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Jan 27 20:01:46 volumio volumio[14370]: info: Updating MyVolumio device info Jan 27 20:01:46 volumio volumio[14370]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 20:01:46 volumio volumio[14370]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 20:01:46 volumio volumio[14370]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 20:01:47 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 20:01:47 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 20:01:47 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 20:01:47 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Jan 27 20:01:47 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 20:01:47 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 20:01:47 volumio go-librespot[14784]: go-librespot daemon starting... Jan 27 20:01:47 volumio volumio[14370]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Jan 27 20:01:47 volumio go-librespot[14785]: time="2026-01-27T20:01:47+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 20:01:47 volumio go-librespot[14785]: time="2026-01-27T20:01:47+07:00" level=debug msg="app state loaded" Jan 27 20:01:47 volumio go-librespot[14785]: time="2026-01-27T20:01:47+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 20:01:47 volumio go-librespot[14785]: time="2026-01-27T20:01:47+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 20:01:47 volumio go-librespot[14785]: time="2026-01-27T20:01:47+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]" Jan 27 20:01:47 volumio go-librespot[14785]: time="2026-01-27T20:01:47+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]" Jan 27 20:01:47 volumio go-librespot[14785]: time="2026-01-27T20:01:47+07:00" level=info msg="zeroconf server listening on port 43575" Jan 27 20:01:48 volumio go-librespot[14785]: time="2026-01-27T20:01:48+07:00" level=debug msg="obtained new client token: AACo67tWsHCGrKtIM7JxT1rWg8bgKvPQlLtdaPklbVNvfRj3yIOUqzWyDhn1emmqChTLfftLJNQxNeQOQLyk3Ju8ura9qJ8xUfC9WaiOwi9vhq4yz+S8IX99WwY8wfcHSZxvFqvwVZENH6SKoqOa84d2dhUld+cVlrujChI90U3aCj8kSrO2Yzi9QcOq8hfghO9zax7UHCqygYGR/j7ll8ieqFWj0KxwRcMSiwdIuUEZ4niUp3Xv5Zf5" Jan 27 20:01:48 volumio go-librespot[14785]: time="2026-01-27T20:01:48+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 20:01:48 volumio go-librespot[14785]: time="2026-01-27T20:01:48+07:00" level=debug msg="completed keyexchange" Jan 27 20:01:48 volumio go-librespot[14785]: time="2026-01-27T20:01:48+07:00" level=debug msg="completed challenge" Jan 27 20:01:48 volumio go-librespot[14785]: time="2026-01-27T20:01:48+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 " Jan 27 20:01:48 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 20:01:48 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 20:01:48 volumio volumio[14370]: info: Initializing connection to go-librespot Websocket Jan 27 20:01:48 volumio volumio[14370]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 27 20:01:49 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 20:01:49 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 20:01:49 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 20:01:50 volumio volumio[14370]: info: MYVOLUMIO: Adding device Jan 27 20:01:50 volumio volumio[14370]: info: MYVOLUMIO: Evaluating Server Jan 27 20:01:51 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 20:01:51 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 20:01:51 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 20:01:51 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Jan 27 20:01:51 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 20:01:51 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 20:01:51 volumio go-librespot[14825]: go-librespot daemon starting... Jan 27 20:01:51 volumio go-librespot[14826]: time="2026-01-27T20:01:51+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 20:01:51 volumio go-librespot[14826]: time="2026-01-27T20:01:51+07:00" level=debug msg="app state loaded" Jan 27 20:01:51 volumio go-librespot[14826]: time="2026-01-27T20:01:51+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 20:01:51 volumio volumio[14370]: info: Initializing connection to go-librespot Websocket Jan 27 20:01:51 volumio go-librespot[14826]: time="2026-01-27T20:01:51+07:00" level=debug msg="new websocket client" Jan 27 20:01:51 volumio volumio[14370]: info: Connection to go-librespot Websocket established Jan 27 20:01:51 volumio volumio[14370]: info: Setting Geolocation for MyVolumio to as1 Jan 27 20:01:51 volumio volumio[14370]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 20:01:51 volumio volumio[14370]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 20:01:51 volumio volumio[14370]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 20:01:52 volumio go-librespot[14826]: time="2026-01-27T20:01:52+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 20:01:52 volumio go-librespot[14826]: time="2026-01-27T20:01:52+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 27 20:01:52 volumio go-librespot[14826]: time="2026-01-27T20:01:52+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 27 20:01:52 volumio go-librespot[14826]: time="2026-01-27T20:01:52+07:00" level=info msg="zeroconf server listening on port 43383" Jan 27 20:01:52 volumio go-librespot[14826]: time="2026-01-27T20:01:52+07:00" level=debug msg="obtained new client token: AADypwZfloOSRKB7HqnlCjODM+nd8YopgJywjLgx+urfHV3Fmf7s4DBtRiCYWQ+5EOtMPNakdu0nYSkEk+yitRe8X7lsSF7mI2tVRSXeTcAZfVaPs270PRMyvkvazO0R5ypZyhiT+9I/yADOIGsJ3V1YPy8zHO4dlBGSoDBBaORbFL8sifiaJ5ntYoFc9jTWXbSiaG0/RgtFkXrBJP03LVJi+cf6HGM1emS1bQwnGrPpqv6nnHe0SC2+hF0=" Jan 27 20:01:52 volumio volumio[14370]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Jan 27 20:01:52 volumio go-librespot[14826]: time="2026-01-27T20:01:52+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Jan 27 20:01:52 volumio go-librespot[14826]: time="2026-01-27T20:01:52+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 27 20:01:52 volumio go-librespot[14826]: time="2026-01-27T20:01:52+07:00" level=debug msg="completed keyexchange" Jan 27 20:01:52 volumio go-librespot[14826]: time="2026-01-27T20:01:52+07:00" level=debug msg="completed challenge" Jan 27 20:01:52 volumio go-librespot[14826]: time="2026-01-27T20:01:52+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 20:01:52 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 20:01:52 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 20:01:52 volumio volumio[14370]: info: Connection to go-librespot Websocket closed Jan 27 20:01:52 volumio volumio[14370]: info: Updating MyVolumio device info Jan 27 20:01:52 volumio volumio[14370]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 20:01:52 volumio volumio[14370]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 20:01:52 volumio volumio[14370]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 20:01:53 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 20:01:53 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 20:01:53 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 20:01:53 volumio volumio[14370]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Jan 27 20:01:53 volumio volumio[14370]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 27 20:01:53 volumio volumio[14370]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 20:01:53 volumio volumio[14370]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Jan 27 20:01:53 volumio volumio-remote-updater[628]: Test mode disabled Jan 27 20:01:53 volumio volumio-remote-updater[628]: Alpha mode disabled Jan 27 20:01:53 volumio volumio-remote-updater[628]: Alpha legacy test mode disabled Jan 27 20:01:53 volumio volumio[14370]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Jan 27 20:01:54 volumio volumio[14370]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Jan 27 20:01:54 volumio volumio[14370]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Jan 27 20:01:54 volumio volumio[14370]: info: Getting Spotify volume Jan 27 20:01:54 volumio volumio[14370]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 27 20:01:55 volumio volumio[14370]: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 27 20:01:55 volumio volumio[14370]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Jan 27 20:01:55 volumio volumio[14370]: errno: -111, Jan 27 20:01:55 volumio volumio[14370]: code: 'ECONNREFUSED', Jan 27 20:01:55 volumio volumio[14370]: syscall: 'connect', Jan 27 20:01:55 volumio volumio[14370]: address: '127.0.0.1', Jan 27 20:01:55 volumio volumio[14370]: port: 9879, Jan 27 20:01:55 volumio volumio[14370]: response: undefined Jan 27 20:01:55 volumio volumio[14370]: } Jan 27 20:01:55 volumio volumio[14370]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 27 20:01:55 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 20:01:55 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 20:01:55 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 20:01:55 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Jan 27 20:01:55 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 20:01:55 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 20:01:55 volumio go-librespot[14849]: go-librespot daemon starting... Jan 27 20:01:55 volumio go-librespot[14850]: time="2026-01-27T20:01:55+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 20:01:55 volumio go-librespot[14850]: time="2026-01-27T20:01:55+07:00" level=debug msg="app state loaded" Jan 27 20:01:55 volumio go-librespot[14850]: time="2026-01-27T20:01:55+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 20:01:56 volumio go-librespot[14850]: time="2026-01-27T20:01:56+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 20:01:56 volumio go-librespot[14850]: time="2026-01-27T20:01:56+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 27 20:01:56 volumio go-librespot[14850]: time="2026-01-27T20:01:56+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 27 20:01:56 volumio sudo[14859]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-27 20:00' Jan 27 20:01:56 volumio sudo[14859]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 20:01:56 volumio go-librespot[14850]: time="2026-01-27T20:01:56+07:00" level=info msg="zeroconf server listening on port 33575" Jan 27 20:01:56 volumio go-librespot[14850]: time="2026-01-27T20:01:56+07:00" level=debug msg="obtained new client token: AAD/w/G7kghWtO4dauEHne88qFJ3q1R2U+SfqlMJ6HBVu/2fGAWosess2GTtfXsg2HYNx0F2QBm4RN4KwVQfb9s5jrdUGjwVjNpb8TUfw9Z+XuLGMAaY4puSAcs/kC5W8ohbkaUUA8WRy5Vau+gozjERbylK52hiwnxkWbelXEh3qOaUTCrN3i4cCbr+O6Jd/GTu8M2mI5SeilH6lv9zZOcuYVsu118dRO2CVTWtFe/jFmQxrtN9Z9TMfdA=" Jan 27 20:01:56 volumio go-librespot[14850]: time="2026-01-27T20:01:56+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 20:01:56 volumio go-librespot[14850]: time="2026-01-27T20:01:56+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" Jan 27 20:01:56 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 20:01:56 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 20:01:56 volumio sudo[14859]: pam_unix(sudo:session): session closed for user root Jan 27 20:01:57 volumio volumio-remote-updater[628]: [2026-01-27 20:01:57] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Jan 27 20:01:57 volumio volumio-remote-updater[628]: [2026-01-27 20:01:57] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Jan 27 20:01:57 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 27 20:01:57 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 27 20:01:57 volumio systemd[1]: volumio.service: Consumed 58.379s CPU time. Jan 27 20:01:57 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 20:01:57 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 20:01:57 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 20:01:57 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 27 20:01:57 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 27 20:01:57 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 9054. Jan 27 20:01:57 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 27 20:01:57 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Jan 27 20:01:57 volumio systemd[1]: volumio.service: Consumed 58.379s CPU time. Jan 27 20:01:57 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Jan 27 20:01:57 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 27 20:01:59 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 20:01:59 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 20:01:59 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 20:01:59 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Jan 27 20:01:59 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 20:01:59 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 20:01:59 volumio go-librespot[14898]: go-librespot daemon starting... Jan 27 20:01:59 volumio go-librespot[14899]: time="2026-01-27T20:01:59+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 20:01:59 volumio go-librespot[14899]: time="2026-01-27T20:01:59+07:00" level=debug msg="app state loaded" Jan 27 20:01:59 volumio go-librespot[14899]: time="2026-01-27T20:01:59+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 20:02:00 volumio go-librespot[14899]: time="2026-01-27T20:02: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]" Jan 27 20:02:00 volumio go-librespot[14899]: time="2026-01-27T20:02: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]" Jan 27 20:02:00 volumio go-librespot[14899]: time="2026-01-27T20:02: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]" Jan 27 20:02:00 volumio go-librespot[14899]: time="2026-01-27T20:02:00+07:00" level=info msg="zeroconf server listening on port 39691" Jan 27 20:02:00 volumio volumio[14883]: info: ------------------------------------------- Jan 27 20:02:00 volumio volumio[14883]: info: ----- Volumio3 ---- Jan 27 20:02:00 volumio volumio[14883]: info: ------------------------------------------- Jan 27 20:02:00 volumio go-librespot[14899]: time="2026-01-27T20:02:00+07:00" level=debug msg="obtained new client token: AAATyv4exBoA2YtKqlhC5CyVjWpHk4qxyS729Jj4GCN9ORHehHWi3ZRyPATeayC9e9h4FmAu89E4Q3sx9qtvaSHxHSIt8SZSkMGQEcr2sOqKc4tP9GIqsuVuKcB8Fj3q6uWiIAxxsKZEY9eBTUjucglWFUiNQ6iAk99ehQ2AjgVVcCPOJeAi2RLZYiqdnnHtDpBDRO69jeRyeerBH2Nq5WYz9gt6p/wiIMZWpZ/RXW+O9rctvZIpkCF2Zs0=" Jan 27 20:02:00 volumio volumio[14883]: info: ----- System startup ---- Jan 27 20:02:00 volumio volumio[14883]: info: ------------------------------------------- Jan 27 20:02:00 volumio go-librespot[14899]: time="2026-01-27T20:02:00+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 20:02:01 volumio go-librespot[14899]: time="2026-01-27T20:02:01+07:00" level=debug msg="completed keyexchange" Jan 27 20:02:01 volumio go-librespot[14899]: time="2026-01-27T20:02:01+07:00" level=debug msg="completed challenge" Jan 27 20:02:01 volumio go-librespot[14899]: time="2026-01-27T20:02:01+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 20:02:01 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 20:02:01 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 20:02:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 20:02:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 20:02:01 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 20:02:02 volumio volumio-remote-updater[628]: [2026-01-27 20:02:02] [connect] Successful connection Jan 27 20:02:02 volumio volumio[14883]: info: MYVOLUMIO Environment detected Jan 27 20:02:02 volumio volumio[14883]: info: Plugin folders cleanup Jan 27 20:02:02 volumio volumio[14883]: info: Scanning into folder /volumio/app/plugins/ Jan 27 20:02:02 volumio volumio[14883]: info: Scanning category audio_interface Jan 27 20:02:02 volumio volumio[14883]: info: Scanning category miscellanea Jan 27 20:02:02 volumio volumio[14883]: info: Scanning category music_service Jan 27 20:02:02 volumio volumio[14883]: info: Scanning category plugins.json Jan 27 20:02:02 volumio volumio[14883]: info: Scanning category system_controller Jan 27 20:02:02 volumio volumio[14883]: info: Scanning category user_interface Jan 27 20:02:02 volumio volumio[14883]: info: Scanning into folder /data/plugins/ Jan 27 20:02:02 volumio volumio[14883]: info: Scanning category music_service Jan 27 20:02:02 volumio volumio[14883]: info: Plugin folders cleanup completed Jan 27 20:02:02 volumio volumio[14883]: info: ------------------------------------------- Jan 27 20:02:02 volumio volumio[14883]: info: ----- Core plugins startup ---- Jan 27 20:02:02 volumio volumio[14883]: info: ------------------------------------------- Jan 27 20:02:02 volumio volumio[14883]: info: Loading plugins from folder /volumio/app/plugins/ Jan 27 20:02:02 volumio volumio[14883]: info: Adding plugin upnp to MyMusic Plugins Jan 27 20:02:02 volumio volumio[14883]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 27 20:02:02 volumio volumio[14883]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 27 20:02:02 volumio volumio[14883]: info: Loading plugins from folder /data/plugins/ Jan 27 20:02:02 volumio volumio[14883]: info: Loading plugin "system"... Jan 27 20:02:02 volumio volumio[14883]: info: Loading plugin "appearance"... Jan 27 20:02:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 20:02:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 20:02:03 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 20:02:04 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Jan 27 20:02:04 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 20:02:04 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 20:02:04 volumio go-librespot[14919]: go-librespot daemon starting... Jan 27 20:02:04 volumio volumio[14883]: info: Loading plugin "network"... Jan 27 20:02:04 volumio go-librespot[14920]: time="2026-01-27T20:02:04+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 20:02:04 volumio go-librespot[14920]: time="2026-01-27T20:02:04+07:00" level=debug msg="app state loaded" Jan 27 20:02:04 volumio volumio[14883]: info: Refreshing Cached IP Addresses Jan 27 20:02:04 volumio go-librespot[14920]: time="2026-01-27T20:02:04+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 20:02:04 volumio sudo[14928]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 27 20:02:04 volumio sudo[14928]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 20:02:04 volumio sudo[14928]: pam_unix(sudo:session): session closed for user root Jan 27 20:02:04 volumio volumio[14883]: info: Loading plugin "services"... Jan 27 20:02:04 volumio sudo[14930]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 27 20:02:04 volumio sudo[14930]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 20:02:04 volumio volumio[14883]: info: Loading plugin "alsa_controller"... Jan 27 20:02:04 volumio sudo[14930]: pam_unix(sudo:session): session closed for user root Jan 27 20:02:04 volumio sudo[14938]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 27 20:02:04 volumio sudo[14938]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 20:02:04 volumio volumio[14883]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 27 20:02:04 volumio volumio[14883]: info: Loading plugin "wizard"... Jan 27 20:02:04 volumio volumio[14883]: info: Loading plugin "networkfs"... Jan 27 20:02:04 volumio volumio[14883]: info: Starting Udev Watcher for removable devices Jan 27 20:02:04 volumio volumio[14883]: info: Ignoring mount for partition: boot Jan 27 20:02:04 volumio volumio[14883]: info: Ignoring mount for partition: volumio Jan 27 20:02:04 volumio volumio[14883]: info: Ignoring mount for partition: volumio_data Jan 27 20:02:04 volumio volumio[14883]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 27 20:02:04 volumio volumio[14883]: info: Loading plugin "volumio_command_line_client"... Jan 27 20:02:04 volumio volumio[14883]: info: Loading plugin "upnp"... Jan 27 20:02:04 volumio volumio[14883]: info: [1769518924785] Starting Upmpd Daemon Jan 27 20:02:04 volumio volumio[14883]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 27 20:02:04 volumio volumio[14883]: info: Loading plugin "my_music"... Jan 27 20:02:04 volumio volumio[14883]: info: Loading plugin "mpd"... Jan 27 20:02:04 volumio go-librespot[14920]: time="2026-01-27T20:02: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]" Jan 27 20:02:04 volumio go-librespot[14920]: time="2026-01-27T20:02: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]" Jan 27 20:02:04 volumio go-librespot[14920]: time="2026-01-27T20:02: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]" Jan 27 20:02:04 volumio go-librespot[14920]: time="2026-01-27T20:02:04+07:00" level=info msg="zeroconf server listening on port 42549" Jan 27 20:02:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 20:02:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 20:02:05 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 20:02:05 volumio go-librespot[14920]: time="2026-01-27T20:02:05+07:00" level=debug msg="obtained new client token: AADliEyvSec3Xy94A4g3yptrsPNC0RqdcDjIa0mJ3mRJPzdXtCr1wY0SAXCTO8p+cVzJzZp2rASpnVoTy7hsfjPtm8N6s8w6UVleWpWvK46uRxV3Y2DfZl3xrSLTbckTNSw31pWRD+aZgZUZKBB7vHjXKhQan7+P8o88zZD82kErWH1d45VQKAIyW6xi8ssVBTrjIy8Z83Mrk/tUjoPGLP2jN3W4XXjzYqEJTTdauX4WjEajrjmEHSmo" Jan 27 20:02:05 volumio go-librespot[14920]: time="2026-01-27T20:02:05+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 20:02:05 volumio go-librespot[14920]: time="2026-01-27T20:02:05+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 27 20:02:05 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 20:02:05 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 20:02:05 volumio volumio[14883]: info: Loading plugin "upnp_browser"... Jan 27 20:02:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 20:02:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 20:02:07 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 20:02:07 volumio sudo[14938]: pam_unix(sudo:session): session closed for user root Jan 27 20:02:08 volumio volumio[14883]: info: Starting UPNP Browser Jan 27 20:02:08 volumio volumio[14883]: info: Loading plugin "alarm-clock"... Jan 27 20:02:08 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Jan 27 20:02:08 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 20:02:08 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 20:02:08 volumio go-librespot[14961]: go-librespot daemon starting... Jan 27 20:02:08 volumio go-librespot[14962]: time="2026-01-27T20:02:08+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 20:02:08 volumio go-librespot[14962]: time="2026-01-27T20:02:08+07:00" level=debug msg="app state loaded" Jan 27 20:02:08 volumio go-librespot[14962]: time="2026-01-27T20:02:08+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 20:02:08 volumio volumio[14883]: info: Loading plugin "airplay_emulation"... Jan 27 20:02:08 volumio volumio[14883]: info: Starting Shairport Sync Jan 27 20:02:08 volumio volumio[14883]: info: Loading plugin "last_100"... Jan 27 20:02:08 volumio volumio[14883]: info: Loading plugin "webradio"... Jan 27 20:02:08 volumio volumio[14883]: info: Loading plugin "i2s_dacs"... Jan 27 20:02:08 volumio volumio[14883]: info: Loading plugin "volumiodiscovery"... Jan 27 20:02:09 volumio volumio[14883]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 27 20:02:09 volumio volumio[14883]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 27 20:02:09 volumio volumio[14883]: *** WARNING *** For more information see Jan 27 20:02:09 volumio volumio[14883]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 27 20:02:09 volumio volumio[14883]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 27 20:02:09 volumio volumio[14883]: *** WARNING *** For more information see Jan 27 20:02:09 volumio node[14883]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 27 20:02:09 volumio node[14883]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 27 20:02:09 volumio node[14883]: *** WARNING *** For more information see Jan 27 20:02:09 volumio node[14883]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 27 20:02:09 volumio node[14883]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 27 20:02:09 volumio node[14883]: *** WARNING *** For more information see Jan 27 20:02:09 volumio volumio[14883]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 27 20:02:09 volumio volumio[14883]: info: Discovery: Started advertising with name: Volumio Jan 27 20:02:09 volumio volumio[14883]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 27 20:02:09 volumio volumio[14883]: info: Loading plugin "spop"... Jan 27 20:02:09 volumio go-librespot[14962]: time="2026-01-27T20:02: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]" Jan 27 20:02:09 volumio go-librespot[14962]: time="2026-01-27T20:02: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]" Jan 27 20:02:09 volumio go-librespot[14962]: time="2026-01-27T20:02: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]" Jan 27 20:02:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 20:02:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 20:02:09 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 20:02:09 volumio go-librespot[14962]: time="2026-01-27T20:02:09+07:00" level=info msg="zeroconf server listening on port 41673" Jan 27 20:02:09 volumio go-librespot[14962]: time="2026-01-27T20:02:09+07:00" level=debug msg="obtained new client token: AAByhoVJ4YxOIZ19VLA4PkYFmUdMoxkwRTj0UP/eAfry/FDh/uklkZjWe/hsBUgIdJTFx9MZyJ661kjFSzq110v2kndrS8hUJNdiWX7EGQr+0cPljJjgIAsv2qRccMHt7dMpNrdFkGj9YAG0dj5vDhMnHNaJicfo3N3O7hutCiyOiAJ7KW9TKGihmvZXxG1EjU1Jn/OA//Vngtdu/o4QyWqpBX1pJa5I6QOnP7FUOlrqcahc24dSAxi9yQA=" Jan 27 20:02:09 volumio go-librespot[14962]: time="2026-01-27T20:02:09+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 20:02:09 volumio go-librespot[14962]: time="2026-01-27T20:02:09+07:00" level=debug msg="completed keyexchange" Jan 27 20:02:09 volumio go-librespot[14962]: time="2026-01-27T20:02:09+07:00" level=debug msg="completed challenge" Jan 27 20:02:09 volumio go-librespot[14962]: time="2026-01-27T20:02:09+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 20:02:09 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 20:02:09 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 20:02:11 volumio volumio[14883]: info: Loading plugin "ytcr"... Jan 27 20:02:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 20:02:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 20:02:11 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 20:02:12 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Jan 27 20:02:12 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 20:02:12 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 20:02:12 volumio go-librespot[14973]: go-librespot daemon starting... Jan 27 20:02:12 volumio go-librespot[14974]: time="2026-01-27T20:02:12+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 20:02:12 volumio go-librespot[14974]: time="2026-01-27T20:02:12+07:00" level=debug msg="app state loaded" Jan 27 20:02:12 volumio go-librespot[14974]: time="2026-01-27T20:02:12+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 20:02:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 20:02:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 20:02:13 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 20:02:13 volumio go-librespot[14974]: time="2026-01-27T20:02:13+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 20:02:13 volumio go-librespot[14974]: time="2026-01-27T20:02:13+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]" Jan 27 20:02:13 volumio go-librespot[14974]: time="2026-01-27T20:02:13+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]" Jan 27 20:02:13 volumio go-librespot[14974]: time="2026-01-27T20:02:13+07:00" level=info msg="zeroconf server listening on port 37735" Jan 27 20:02:13 volumio volumio[14883]: info: Loading plugin "ytmusic"... Jan 27 20:02:13 volumio go-librespot[14974]: time="2026-01-27T20:02:13+07:00" level=debug msg="obtained new client token: AAAhsXg3Gi+kAj5BinIJX83hWP8smtNHZwguDSBY3w4ZqBSPbjL2BCbzpz4Bq0IZj86Vp0vpKqkwjZJyUdKQ+DcSyh0jDl9lhVLtLEjFuh8NBVY/ZI/NZMNv3GvXCcSy+8+0iZjI7vmisFK7RHqnzh0/T3ebf4bPjNhoXvy3f+CMuf5HQldyrVL82vmR0wxKL+2DCbxPBZL+y+6n0EnVfEYb8sK2jsH+kUmKxgRqUuVm76yo5uCO28nkJs4=" Jan 27 20:02:13 volumio go-librespot[14974]: time="2026-01-27T20:02:13+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 20:02:13 volumio go-librespot[14974]: time="2026-01-27T20:02:13+07:00" level=debug msg="completed keyexchange" Jan 27 20:02:13 volumio go-librespot[14974]: time="2026-01-27T20:02:13+07:00" level=debug msg="completed challenge" Jan 27 20:02:14 volumio go-librespot[14974]: time="2026-01-27T20:02: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 " Jan 27 20:02:14 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 20:02:14 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 20:02:14 volumio volumio-remote-updater[628]: [2026-01-27 20:02:14] [connect] Successful connection Jan 27 20:02:14 volumio volumio[14883]: info: Loading plugin "outputs"... Jan 27 20:02:14 volumio volumio[14883]: info: Loading plugin "albumart"... Jan 27 20:02:14 volumio volumio[14883]: info: Plugin example_plugin is not enabled Jan 27 20:02:14 volumio volumio[14883]: info: Loading plugin "inputs"... Jan 27 20:02:14 volumio volumio[14883]: info: Loading plugin "updater_comm"... Jan 27 20:02:14 volumio volumio[14883]: info: Plugin mpdemulation is not enabled Jan 27 20:02:14 volumio volumio[14883]: info: Loading plugin "rest_api"... Jan 27 20:02:15 volumio volumio[14883]: info: Loading plugin "websocket"... Jan 27 20:02:15 volumio volumio[14883]: info: Starting Socket.io Server version 1.7.4 Jan 27 20:02:15 volumio volumio[14883]: info: Loading plugin "RoonBridge"... Jan 27 20:02:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 20:02:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 20:02:15 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 20:02:15 volumio volumio[14883]: info: Applying required configuration parameters for plugin RoonBridge Jan 27 20:02:15 volumio volumio[14883]: info: Loading i18n strings for locale en Jan 27 20:02:15 volumio volumio[14883]: Updating browse sources language Jan 27 20:02:15 volumio volumio[14883]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 20:02:15 volumio volumio[14995]: Forking 3 albumart workers Jan 27 20:02:15 volumio volumio[14883]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 27 20:02:15 volumio volumio[14883]: info: CoreCommandRouter::initPlayerControls Jan 27 20:02:15 volumio volumio[14883]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:02:15 volumio volumio[14883]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:02:15 volumio volumio[14883]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:02:15 volumio volumio[14883]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:02:15 volumio volumio[14883]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:02:15 volumio volumio[14883]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:02:15 volumio volumio[14883]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:02:15 volumio volumio[14883]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:02:15 volumio volumio[14883]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 27 20:02:15 volumio volumio[14883]: Express server listening on port 3000 Jan 27 20:02:15 volumio volumio[14883]: [Metrics] WebUI: 16s 87.62ms Jan 27 20:02:16 volumio volumio[14883]: info: CoreStateMachine::resetVolumioState Jan 27 20:02:16 volumio volumio[14883]: info: CoreStateMachine::getcurrentVolume Jan 27 20:02:16 volumio volumio[14883]: info: CoreCommandRouter::volumioRetrievevolume Jan 27 20:02:16 volumio sudo[15041]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 27 20:02:16 volumio sudo[15041]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 20:02:16 volumio sudo[15041]: pam_unix(sudo:session): session closed for user root Jan 27 20:02:16 volumio sudo[15039]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 27 20:02:16 volumio volumio[14883]: info: Volumio Network Manager: Network status updated: 1 Jan 27 20:02:16 volumio sudo[15039]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 20:02:16 volumio sudo[15039]: pam_unix(sudo:session): session closed for user root Jan 27 20:02:16 volumio volumio[14883]: info: VolumeController:: Volume=100 Mute =false Jan 27 20:02:16 volumio volumio[14883]: info: CoreStateMachine::pushState Jan 27 20:02:16 volumio volumio[14883]: info: CorePlayQueue::getTrack 0 Jan 27 20:02:16 volumio volumio[14883]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 27 20:02:16 volumio volumio[14883]: info: CoreCommandRouter::volumioPushState Jan 27 20:02:16 volumio volumio[14883]: info: CoreStateMachine::updateTrackBlock Jan 27 20:02:16 volumio volumio[14883]: info: CorePlayQueue::getTrackBlock Jan 27 20:02:16 volumio volumio[14883]: info: CoreCommandRouter::volumioRetrievevolume Jan 27 20:02:16 volumio volumio-remote-updater[628]: [2026-01-27 20:02:16] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1769518934 101 Jan 27 20:02:16 volumio volumio[14883]: 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 Jan 27 20:02:16 volumio volumio[14883]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 20:02:16 volumio volumio[14883]: info: Reloading queue from file Jan 27 20:02:16 volumio volumio[14883]: info: CoreStateMachine::setRepeat null single undefined Jan 27 20:02:16 volumio volumio[14883]: info: CoreStateMachine::pushState Jan 27 20:02:16 volumio volumio[14883]: info: CorePlayQueue::getTrack 0 Jan 27 20:02:16 volumio volumio[14883]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 27 20:02:16 volumio volumio[14883]: info: CoreCommandRouter::volumioPushState Jan 27 20:02:16 volumio volumio[14883]: info: CoreStateMachine::setRandom null Jan 27 20:02:16 volumio volumio[14883]: info: CoreStateMachine::pushState Jan 27 20:02:16 volumio volumio[14883]: info: CorePlayQueue::getTrack 0 Jan 27 20:02:16 volumio volumio[14883]: info: CoreCommandRouter::volumioPushState Jan 27 20:02:16 volumio volumio[14883]: info: Setting Device type: Raspberry PI Jan 27 20:02:16 volumio volumio[14883]: info: Completed loading Core Plugins Jan 27 20:02:16 volumio volumio[14883]: info: Preparing to generate the ALSA configuration file Jan 27 20:02:16 volumio volumio[14883]: info: VolumeController:: Volume=100 Mute =false Jan 27 20:02:16 volumio volumio[14883]: info: CoreStateMachine::pushState Jan 27 20:02:16 volumio volumio[14883]: info: CorePlayQueue::getTrack 0 Jan 27 20:02:16 volumio volumio[14883]: info: CoreCommandRouter::volumioPushState Jan 27 20:02:17 volumio volumio[14883]: info: Asound.conf file unchanged, so no further update is needed Jan 27 20:02:17 volumio volumio[14883]: info: Output device has changed, restarting MPD Jan 27 20:02:17 volumio volumio[14883]: info: Output device has changed, restarting Shairport Sync Jan 27 20:02:17 volumio volumio[14883]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:02:17 volumio volumio[14883]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 20:02:17 volumio sudo[15056]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 27 20:02:17 volumio sudo[15056]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 20:02:17 volumio sudo[15058]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 27 20:02:17 volumio sudo[15058]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 20:02:17 volumio sudo[15058]: pam_unix(sudo:session): session closed for user root Jan 27 20:02:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 20:02:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 20:02:17 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 20:02:17 volumio sudo[15060]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 27 20:02:17 volumio sudo[15060]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 20:02:17 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Jan 27 20:02:17 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 20:02:17 volumio volumio[14883]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 27 20:02:17 volumio volumio[14883]: info: ___________ START PLUGINS ___________ Jan 27 20:02:17 volumio volumio[14883]: info: ControllerMpd::onStart: Initializing MPD Jan 27 20:02:17 volumio volumio[14883]: info: Creating MPD Configuration file Jan 27 20:02:17 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 20:02:17 volumio go-librespot[15068]: go-librespot daemon starting... Jan 27 20:02:17 volumio sudo[15070]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 27 20:02:17 volumio sudo[15070]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 20:02:17 volumio sudo[15070]: pam_unix(sudo:session): session closed for user root Jan 27 20:02:17 volumio go-librespot[15073]: time="2026-01-27T20:02:17+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 20:02:17 volumio go-librespot[15073]: time="2026-01-27T20:02:17+07:00" level=debug msg="app state loaded" Jan 27 20:02:17 volumio go-librespot[15073]: time="2026-01-27T20:02:17+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 20:02:17 volumio volumio[14883]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 27 20:02:17 volumio sudo[15056]: pam_unix(sudo:session): session closed for user root Jan 27 20:02:17 volumio volumio[14883]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 20:02:17 volumio volumio[14883]: info: [1769518937435] CoreMusicLibrary::Adding element Media Servers Jan 27 20:02:17 volumio volumio[14883]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 20:02:17 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 27 20:02:17 volumio sudo[15072]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 27 20:02:17 volumio volumio[14883]: info: UPNP Browser: Client initialized successfully Jan 27 20:02:17 volumio sudo[15072]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 20:02:17 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 27 20:02:17 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 27 20:02:17 volumio systemd[1]: mpd.service: Consumed 7.048s CPU time. Jan 27 20:02:17 volumio volumio[14883]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:02:17 volumio volumio[14883]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 20:02:17 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 27 20:02:17 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 27 20:02:17 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 27 20:02:17 volumio volumio[14883]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 27 20:02:17 volumio volumio[14883]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:02:17 volumio volumio[14883]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 20:02:17 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 27 20:02:17 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 27 20:02:17 volumio volumio[14883]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 27 20:02:17 volumio volumio[14883]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 20:02:17 volumio volumio[14883]: info: [1769518937823] CoreMusicLibrary::Adding element Last_100 Jan 27 20:02:17 volumio volumio[14883]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 20:02:17 volumio volumio[14883]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 20:02:17 volumio volumio[14883]: info: [1769518937894] CoreMusicLibrary::Adding element Webradio Jan 27 20:02:17 volumio volumio[14883]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 20:02:17 volumio volumio[14883]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 27 20:02:17 volumio volumio[14883]: info: Initializing BBC Radios Jan 27 20:02:18 volumio go-librespot[15073]: time="2026-01-27T20:02: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-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 20:02:18 volumio go-librespot[15073]: time="2026-01-27T20:02:18+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]" Jan 27 20:02:18 volumio go-librespot[15073]: time="2026-01-27T20:02:18+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]" Jan 27 20:02:18 volumio go-librespot[15073]: time="2026-01-27T20:02:18+07:00" level=info msg="zeroconf server listening on port 42973" Jan 27 20:02:18 volumio volumio[14883]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 27 20:02:18 volumio volumio[14883]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 20:02:18 volumio sudo[15088]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 27 20:02:18 volumio sudo[15088]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 27 20:02:18 volumio sudo[15088]: pam_unix(sudo:session): session closed for user root Jan 27 20:02:18 volumio volumio[14883]: info: Creating Spotify config file Jan 27 20:02:18 volumio volumio[14883]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:02:18 volumio go-librespot[15073]: time="2026-01-27T20:02:18+07:00" level=debug msg="obtained new client token: AAD4qZtIfdBRcwvwQkG2A0w9VskKa+6BVJULQYyRSVc9KVV9PZ7+ENyR/d9+AAV3VfdVv4JJmGNs96n7LYyrai8Pk1wvlS3ManwzB1lgIiV5JuU/WaZqn2dWZu0p8VIUGJ/LEXXm10gaDwLqesgCIXu1eF4P/ONew6evotR3Gn4D+nNSncG7japuPlS4QCrlZ9hvAr8AkJPsrjRJUfp+a65HmlKzemh8YuKo91o38pzl9qvukcMXqPlGr1g=" Jan 27 20:02:18 volumio go-librespot[15073]: time="2026-01-27T20:02:18+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 20:02:18 volumio go-librespot[15073]: time="2026-01-27T20:02:18+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" Jan 27 20:02:18 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 20:02:18 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 20:02:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 20:02:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 20:02:19 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 20:02:19 volumio volumio[15007]: Starting albumart workers Jan 27 20:02:19 volumio volumio[15005]: Starting albumart workers Jan 27 20:02:19 volumio volumio[14883]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 20:02:19 volumio volumio[14883]: info: [1769518939377] CoreMusicLibrary::Adding element YouTube Music Jan 27 20:02:19 volumio volumio[14883]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 20:02:19 volumio volumio[14883]: Cannot find translation for source YouTube Music Jan 27 20:02:19 volumio volumio[14883]: info: Volumio Calling Home Jan 27 20:02:19 volumio sudo[15109]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Jan 27 20:02:19 volumio sudo[15109]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 20:02:19 volumio sudo[15109]: pam_unix(sudo:session): session closed for user root Jan 27 20:02:19 volumio volumio[15006]: Starting albumart workers Jan 27 20:02:20 volumio volumio[14883]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Jan 27 20:02:20 volumio volumio[14883]: info: Discovery: Found device Volumio Jan 27 20:02:20 volumio volumio[14883]: info: CoreCommandRouter::volumioGetState Jan 27 20:02:20 volumio volumio[14883]: info: CorePlayQueue::getTrack 0 Jan 27 20:02:20 volumio volumio[14883]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Jan 27 20:02:20 volumio volumio[14883]: info: Discovery: Found device Volumio Jan 27 20:02:20 volumio volumio[14883]: info: CoreCommandRouter::volumioGetState Jan 27 20:02:20 volumio volumio[14883]: info: CorePlayQueue::getTrack 0 Jan 27 20:02:20 volumio volumio[14883]: info: MPD Permissions set Jan 27 20:02:20 volumio volumio[14883]: info: MPD Permissions set Jan 27 20:02:20 volumio volumio[14883]: info: Upmpdcli Daemon Started Jan 27 20:02:20 volumio volumio[14883]: info: Volumio called home Jan 27 20:02:20 volumio volumio[14883]: info: Spotify config file written Jan 27 20:02:20 volumio sudo[15115]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 27 20:02:20 volumio sudo[15115]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 20:02:20 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 20:02:20 volumio volumio[14883]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 2 Jan 27 20:02:20 volumio volumio[14883]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:02:20 volumio volumio[14883]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:02:20 volumio volumio[14883]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:02:20 volumio volumio[14883]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:02:20 volumio volumio[14883]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:02:20 volumio volumio[14883]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:02:20 volumio volumio[14883]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:02:20 volumio volumio[14883]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:02:20 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 20:02:20 volumio go-librespot[15117]: go-librespot daemon starting... Jan 27 20:02:20 volumio sudo[15115]: pam_unix(sudo:session): session closed for user root Jan 27 20:02:20 volumio volumio[14883]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 20:02:20 volumio volumio[14883]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:02:20 volumio go-librespot[15119]: time="2026-01-27T20:02:20+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 20:02:20 volumio go-librespot[15119]: time="2026-01-27T20:02:20+07:00" level=debug msg="app state loaded" Jan 27 20:02:20 volumio go-librespot[15119]: time="2026-01-27T20:02:20+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 20:02:20 volumio volumio[14883]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:02:20 volumio volumio[14883]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:02:20 volumio volumio[14883]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:02:20 volumio volumio[14883]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:02:20 volumio volumio[14883]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:02:20 volumio volumio[14883]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:02:20 volumio volumio[14883]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:02:20 volumio volumio[14883]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:02:21 volumio volumio[14883]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 20:02:21 volumio volumio[14883]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 27 20:02:21 volumio volumio[14883]: info: No need to fix Spotify hosts Jan 27 20:02:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 20:02:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 20:02:21 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 20:02:21 volumio go-librespot[15119]: time="2026-01-27T20:02: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-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 20:02:21 volumio go-librespot[15119]: time="2026-01-27T20:02:21+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]" Jan 27 20:02:21 volumio go-librespot[15119]: time="2026-01-27T20:02:21+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]" Jan 27 20:02:21 volumio go-librespot[15119]: time="2026-01-27T20:02:21+07:00" level=info msg="zeroconf server listening on port 36689" Jan 27 20:02:21 volumio go-librespot[15119]: time="2026-01-27T20:02:21+07:00" level=debug msg="obtained new client token: AACsNqGOI3xUnOyjvAiIf+YRX3XeKjDMdV8vlT3Y2jZsbNywMSOe77aEF97UOkhsH43P60gFGfpg3RVqMQjbHliG45F4ToulekCcrZ4yuN3DpJXZknkHqgs7V2jZ6YyHFg+mcaCMtaQ2JuGBdVk1ri0+n9QmGoSgFmucXnF12A4j9YxvojB8uCA7v1hKxGTvJcp5t069rqiHSn+bs3xVK5UF5TRTcJNmn0T9zv2k6bMcvXSKNfWWHW9mXFE=" Jan 27 20:02:22 volumio go-librespot[15119]: time="2026-01-27T20:02:22+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 20:02:22 volumio volumio[14883]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 27 20:02:22 volumio volumio[14883]: SPOTIFY: BQDN1HDXrdSy5d4BTSr24wKCOVa9Y66bNwJeH8fBc5TaPwyH5fdVWr10B5OA2VtromoIQV5IMOCvjF7SUBxoAWMinK4dBiAXY56eHDXWqDl1OHdoCh91YkJLeZDmakPmGMmze-wPxZRUn_ZL1y9O2wxFt5PqOfPqzoRkX2-wz3x1vZ14k9u3PW7I08DPXCX7MAt5k0nXBbaIXajUR2gZWVbbC5XSwuClnVRtm2e7H_BKELfpxDrae59hXrEz1BpFpHpOtdqAxcndryNo4iwpIqHZfq24hHxAOk4FMM5hQnXCkhdmSG2QflJE Jan 27 20:02:22 volumio volumio[14883]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 27 20:02:22 volumio volumio[14883]: info: New Spotify access token = BQDN1HDXrdSy5d4BTSr24wKCOVa9Y66bNwJeH8fBc5TaPwyH5fdVWr10B5OA2VtromoIQV5IMOCvjF7SUBxoAWMinK4dBiAXY56eHDXWqDl1OHdoCh91YkJLeZDmakPmGMmze-wPxZRUn_ZL1y9O2wxFt5PqOfPqzoRkX2-wz3x1vZ14k9u3PW7I08DPXCX7MAt5k0nXBbaIXajUR2gZWVbbC5XSwuClnVRtm2e7H_BKELfpxDrae59hXrEz1BpFpHpOtdqAxcndryNo4iwpIqHZfq24hHxAOk4FMM5hQnXCkhdmSG2QflJE Jan 27 20:02:22 volumio volumio[14883]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 27 20:02:22 volumio go-librespot[15119]: time="2026-01-27T20:02:22+07:00" level=debug msg="completed keyexchange" Jan 27 20:02:22 volumio go-librespot[15119]: time="2026-01-27T20:02:22+07:00" level=debug msg="completed challenge" Jan 27 20:02:22 volumio volumio[14883]: info: Starting Shairport Sync Jan 27 20:02:22 volumio volumio[14883]: info: Starting Shairport Sync Jan 27 20:02:22 volumio go-librespot[15119]: time="2026-01-27T20:02:22+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 20:02:22 volumio volumio[14883]: info: Starting Shairport Sync Jan 27 20:02:22 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 20:02:22 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 20:02:22 volumio sudo[15156]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 27 20:02:22 volumio sudo[15156]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 20:02:22 volumio sudo[15159]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 27 20:02:22 volumio sudo[15159]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 20:02:22 volumio sudo[15161]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 27 20:02:22 volumio sudo[15161]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 20:02:22 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 27 20:02:22 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 27 20:02:22 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 27 20:02:22 volumio systemd[1]: shairport-sync.service: Consumed 2.386s CPU time. Jan 27 20:02:22 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 27 20:02:22 volumio sudo[15156]: pam_unix(sudo:session): session closed for user root Jan 27 20:02:22 volumio volumio[14883]: info: Shairport-Sync Started Jan 27 20:02:22 volumio volumio[14883]: Error adding Membership: Error: addMembership EINVAL Jan 27 20:02:22 volumio volumio[14883]: info: CoreCommandRouter::volumioGetState Jan 27 20:02:22 volumio volumio[14883]: info: CorePlayQueue::getTrack 0 Jan 27 20:02:22 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 27 20:02:22 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 27 20:02:22 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 27 20:02:22 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 27 20:02:22 volumio sudo[15161]: pam_unix(sudo:session): session closed for user root Jan 27 20:02:22 volumio sudo[15159]: pam_unix(sudo:session): session closed for user root Jan 27 20:02:23 volumio volumio[14883]: info: Shairport-Sync Started Jan 27 20:02:23 volumio volumio[14883]: info: Shairport-Sync Started Jan 27 20:02:23 volumio volumio[14883]: 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"} Jan 27 20:02:23 volumio volumio[14883]: info: Spotify Successfully logged in Jan 27 20:02:23 volumio volumio[14883]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 27 20:02:23 volumio volumio[14883]: info: [1769518943069] CoreMusicLibrary::Adding element Spotify Jan 27 20:02:23 volumio volumio[14883]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 27 20:02:23 volumio volumio[14883]: Cannot find translation for source YouTube Music Jan 27 20:02:23 volumio volumio[14883]: Cannot find translation for source Spotify Jan 27 20:02:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 20:02:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 20:02:23 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 20:02:23 volumio volumio[14883]: info: [yt-cast-receiver] DIAL server listening on port 8098 Jan 27 20:02:23 volumio volumio[14883]: info: CoreCommandRouter::volumioRetrievevolume Jan 27 20:02:24 volumio volumio[14883]: info: VolumeController:: Volume=100 Mute =false Jan 27 20:02:24 volumio volumio[14883]: info: CoreCommandRouter::volumioGetState Jan 27 20:02:24 volumio volumio[14883]: info: CorePlayQueue::getTrack 0 Jan 27 20:02:24 volumio volumio[14883]: info: CoreStateMachine::pushState Jan 27 20:02:24 volumio volumio[14883]: info: CorePlayQueue::getTrack 0 Jan 27 20:02:24 volumio volumio[14883]: info: CoreCommandRouter::volumioPushState Jan 27 20:02:25 volumio volumio[14883]: info: go-librespot daemon successfully initialized Jan 27 20:02:25 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 20:02:25 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 20:02:25 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 20:02:25 volumio mpd[15106]: 2026-01-27T20:02:25 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 27 20:02:25 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 27 20:02:25 volumio sudo[15060]: pam_unix(sudo:session): session closed for user root Jan 27 20:02:25 volumio sudo[15072]: pam_unix(sudo:session): session closed for user root Jan 27 20:02:25 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Jan 27 20:02:25 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 20:02:25 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 20:02:25 volumio go-librespot[15213]: go-librespot daemon starting... Jan 27 20:02:25 volumio go-librespot[15215]: time="2026-01-27T20:02:25+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 20:02:25 volumio go-librespot[15215]: time="2026-01-27T20:02:25+07:00" level=debug msg="app state loaded" Jan 27 20:02:25 volumio go-librespot[15215]: time="2026-01-27T20:02:25+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 20:02:25 volumio volumio[14883]: error: MPD error: The expression evaluated to a falsy value: Jan 27 20:02:25 volumio volumio[14883]: assert.ok(self.idling) Jan 27 20:02:25 volumio volumio[14883]: error: The expression evaluated to a falsy value: Jan 27 20:02:25 volumio volumio[14883]: assert.ok(self.idling) Jan 27 20:02:25 volumio volumio[14883]: info: MPD running with PID15106 Jan 27 20:02:25 volumio volumio[14883]: ,establishing connection Jan 27 20:02:25 volumio volumio[14883]: error: updateQueue error: null Jan 27 20:02:25 volumio volumio[14883]: error: updateQueue error: null Jan 27 20:02:25 volumio volumio[14883]: info: Completed starting Core Plugins Jan 27 20:02:25 volumio volumio[14883]: info: ------------------------------------------- Jan 27 20:02:25 volumio volumio[14883]: info: ----- MyVolumio plugins startup ---- Jan 27 20:02:25 volumio volumio[14883]: info: ------------------------------------------- Jan 27 20:02:25 volumio volumio[14883]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 27 20:02:25 volumio go-librespot[15215]: time="2026-01-27T20:02: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-gew1.spotify.com:80]" Jan 27 20:02:25 volumio go-librespot[15215]: time="2026-01-27T20:02:25+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]" Jan 27 20:02:25 volumio go-librespot[15215]: time="2026-01-27T20:02:25+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]" Jan 27 20:02:25 volumio go-librespot[15215]: time="2026-01-27T20:02:25+07:00" level=info msg="zeroconf server listening on port 32789" Jan 27 20:02:26 volumio go-librespot[15215]: time="2026-01-27T20:02:26+07:00" level=debug msg="obtained new client token: AACLKb1NHO4aWfdGFDtpANryyqTSPfwY5HYnfwU+8mMm9wl4VV1zO1HErEZSMz6G/opJra+EkrPZQ2BWZpte+p7E0+spRu4bMg4wWWFMiBQIzqvbgo98AOXhSG6XIxEuLB5v/C1MXcuQQm0AKyJevTJzuFNYzQ9Ruy2B6jyRvKtrg3ZCSqY4Kv3hCKbbpvT9tcM+r3dKYzr+D1QxAFRjuCwFS40FOFlA6f2TlpZMgM2iq5u/BCCm75vQ" Jan 27 20:02:26 volumio go-librespot[15215]: time="2026-01-27T20:02:26+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" Jan 27 20:02:26 volumio go-librespot[15215]: time="2026-01-27T20:02:26+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 27 20:02:26 volumio go-librespot[15215]: time="2026-01-27T20:02:26+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 27 20:02:26 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 20:02:26 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 20:02:27 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 20:02:27 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 20:02:27 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 20:02:28 volumio volumio[14883]: info: Initializing connection to go-librespot Websocket Jan 27 20:02:28 volumio volumio[14883]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 27 20:02:29 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 20:02:29 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 20:02:29 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 20:02:29 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Jan 27 20:02:29 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 20:02:29 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 20:02:29 volumio go-librespot[15222]: go-librespot daemon starting... Jan 27 20:02:29 volumio go-librespot[15223]: time="2026-01-27T20:02:29+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 20:02:29 volumio go-librespot[15223]: time="2026-01-27T20:02:29+07:00" level=debug msg="app state loaded" Jan 27 20:02:29 volumio go-librespot[15223]: time="2026-01-27T20:02:29+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 20:02:30 volumio go-librespot[15223]: time="2026-01-27T20:02:30+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 27 20:02:30 volumio go-librespot[15223]: time="2026-01-27T20:02:30+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 27 20:02:30 volumio go-librespot[15223]: time="2026-01-27T20:02:30+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 27 20:02:30 volumio go-librespot[15223]: time="2026-01-27T20:02:30+07:00" level=info msg="zeroconf server listening on port 35105" Jan 27 20:02:30 volumio go-librespot[15223]: time="2026-01-27T20:02:30+07:00" level=debug msg="obtained new client token: AABUPwPQ+fgIVI5UuBSNOv4fddYvqmtmxO2c7V4SGTTCpot2SOCWZo6JWn3SICp7d1SoopNAQZUbVr/uha7+PTac+arA8b2nlY4ihx6CdAG6VqhsTxadk8Vjw9r3/ryQ0DAUx3C5Cnl3wOeJYPjuDxQnGKGjeNErEBHLkhSo0j4AYCEH7aEwJJIFU20ZZRf/8njCI9EXHK/piq7PexDfuNZaJxTPU1mzoH0tJTWnBqViZ7OeCUehWTPh" Jan 27 20:02:30 volumio go-librespot[15223]: time="2026-01-27T20:02:30+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 20:02:30 volumio volumio[14883]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 27 20:02:30 volumio go-librespot[15223]: time="2026-01-27T20:02:30+07:00" level=debug msg="completed keyexchange" Jan 27 20:02:30 volumio go-librespot[15223]: time="2026-01-27T20:02:30+07:00" level=debug msg="completed challenge" Jan 27 20:02:30 volumio go-librespot[15223]: time="2026-01-27T20:02: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 " Jan 27 20:02:30 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 20:02:30 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 20:02:31 volumio volumio[14883]: info: Initializing connection to go-librespot Websocket Jan 27 20:02:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 20:02:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 20:02:31 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 20:02:31 volumio volumio[14883]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 27 20:02:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 20:02:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 20:02:33 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 20:02:33 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15. Jan 27 20:02:33 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 20:02:33 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 20:02:33 volumio go-librespot[15231]: go-librespot daemon starting... Jan 27 20:02:33 volumio go-librespot[15232]: time="2026-01-27T20:02:33+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 20:02:33 volumio go-librespot[15232]: time="2026-01-27T20:02:33+07:00" level=debug msg="app state loaded" Jan 27 20:02:33 volumio go-librespot[15232]: time="2026-01-27T20:02:33+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 20:02:34 volumio volumio[14883]: info: Initializing connection to go-librespot Websocket Jan 27 20:02:34 volumio go-librespot[15232]: time="2026-01-27T20:02:34+07:00" level=debug msg="new websocket client" Jan 27 20:02:34 volumio volumio[14883]: info: Connection to go-librespot Websocket established Jan 27 20:02:34 volumio go-librespot[15232]: time="2026-01-27T20:02: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]" Jan 27 20:02:34 volumio go-librespot[15232]: time="2026-01-27T20:02: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]" Jan 27 20:02:34 volumio go-librespot[15232]: time="2026-01-27T20:02: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]" Jan 27 20:02:34 volumio go-librespot[15232]: time="2026-01-27T20:02:34+07:00" level=info msg="zeroconf server listening on port 41451" Jan 27 20:02:34 volumio volumio[14883]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 27 20:02:34 volumio volumio[14883]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 27 20:02:34 volumio volumio[14883]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 27 20:02:34 volumio volumio[14883]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jan 27 20:02:34 volumio volumio[14883]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 27 20:02:34 volumio volumio[14883]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 27 20:02:34 volumio volumio[14883]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 27 20:02:34 volumio volumio[14883]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 27 20:02:34 volumio volumio[14883]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 27 20:02:34 volumio volumio[14883]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 27 20:02:34 volumio volumio[14883]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jan 27 20:02:34 volumio volumio[14883]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 27 20:02:34 volumio volumio[14883]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 27 20:02:34 volumio volumio[14883]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 27 20:02:34 volumio volumio[14883]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jan 27 20:02:34 volumio volumio[14883]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 27 20:02:34 volumio volumio[14883]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 27 20:02:34 volumio volumio[14883]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 27 20:02:34 volumio volumio[14883]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 27 20:02:34 volumio volumio[14883]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 27 20:02:34 volumio volumio[14883]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 27 20:02:34 volumio volumio[14883]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jan 27 20:02:34 volumio volumio[14883]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 27 20:02:34 volumio volumio[14883]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jan 27 20:02:34 volumio volumio[14883]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 27 20:02:34 volumio volumio[14883]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 27 20:02:34 volumio volumio[14883]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 27 20:02:34 volumio volumio[14883]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 27 20:02:34 volumio volumio[14883]: info: Adding plugin bluetooth to MyMusic Plugins Jan 27 20:02:34 volumio volumio[14883]: info: Adding plugin multiroom to MyMusic Plugins Jan 27 20:02:34 volumio volumio[14883]: info: Adding plugin metavolumio to MyMusic Plugins Jan 27 20:02:34 volumio volumio[14883]: info: Adding plugin cd_controller to MyMusic Plugins Jan 27 20:02:34 volumio volumio[14883]: info: Adding plugin qobuzconnect to MyMusic Plugins Jan 27 20:02:34 volumio volumio[14883]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 27 20:02:34 volumio volumio[14883]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 27 20:02:34 volumio volumio[14883]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 27 20:02:34 volumio go-librespot[15232]: time="2026-01-27T20:02:34+07:00" level=debug msg="obtained new client token: AAD71aaZy9sQ9yl7xwHUwtUW8+oIiDpW1THPExbfme5ogudnhm29uCQuIfpbWfAu6E45nW1ehqW2MKt6fqGjzCdYUI+WEwTWLHuuiLJXvsosXNpD/ocQsxHcGWcLIaKVNe4ijBjHdfv8EMTK/yE7S5PY9ugY/xaZQrWmKDZjh4AiJO0t3htxApZrNrvK8SaLhcsLXHuSTDGHbCQUghACLRGDIvw5uFnf4D91YSGkz4e+e3F3rlB2/JOcyYo=" Jan 27 20:02:34 volumio go-librespot[15232]: time="2026-01-27T20:02:34+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" Jan 27 20:02:34 volumio go-librespot[15232]: time="2026-01-27T20:02:34+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 27 20:02:34 volumio go-librespot[15232]: time="2026-01-27T20:02:34+07:00" level=debug msg="completed keyexchange" Jan 27 20:02:34 volumio go-librespot[15232]: time="2026-01-27T20:02:34+07:00" level=debug msg="completed challenge" Jan 27 20:02:34 volumio go-librespot[15232]: time="2026-01-27T20:02:34+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 27 20:02:34 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 20:02:34 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 20:02:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 20:02:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 20:02:35 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 20:02:36 volumio volumio[14883]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 27 20:02:36 volumio volumio[14883]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 27 20:02:36 volumio volumio[14883]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 20:02:36 volumio volumio[14883]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 27 20:02:36 volumio volumio[14883]: info: Starting MyVolumio Remote Streaming Endpoints Jan 27 20:02:36 volumio volumio[14883]: info: MyVolumio login type: Token Jan 27 20:02:36 volumio volumio[14883]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 27 20:02:36 volumio volumio[14883]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 27 20:02:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 20:02:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 20:02:37 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 20:02:37 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Jan 27 20:02:37 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 27 20:02:38 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 27 20:02:38 volumio go-librespot[15253]: go-librespot daemon starting... Jan 27 20:02:38 volumio go-librespot[15254]: time="2026-01-27T20:02:38+07:00" level=info msg="running go-librespot 0.4.0" Jan 27 20:02:38 volumio go-librespot[15254]: time="2026-01-27T20:02:38+07:00" level=debug msg="app state loaded" Jan 27 20:02:38 volumio go-librespot[15254]: time="2026-01-27T20:02:38+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 27 20:02:38 volumio volumio[14883]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 27 20:02:38 volumio volumio[14883]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 27 20:02:38 volumio volumio[14883]: info: Streaming services startup Jan 27 20:02:38 volumio volumio[14883]: info: Starting Streaming Daemon Jan 27 20:02:38 volumio sudo[15262]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 27 20:02:38 volumio sudo[15262]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 27 20:02:38 volumio volumio[14883]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 27 20:02:38 volumio sudo[15262]: pam_unix(sudo:session): session closed for user root Jan 27 20:02:38 volumio volumio[14883]: info: Getting Spotify volume Jan 27 20:02:38 volumio volumio[14883]: info: Connection to go-librespot Websocket closed Jan 27 20:02:38 volumio volumio[14883]: error: Cannot start Volumio Streaming Daemon Jan 27 20:02:38 volumio volumio[14883]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 27 20:02:38 volumio volumio[14883]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 27 20:02:38 volumio volumio[14883]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 3 Jan 27 20:02:38 volumio go-librespot[15254]: time="2026-01-27T20:02:38+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]" Jan 27 20:02:38 volumio go-librespot[15254]: time="2026-01-27T20:02:38+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]" Jan 27 20:02:38 volumio go-librespot[15254]: time="2026-01-27T20:02:38+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]" Jan 27 20:02:38 volumio go-librespot[15254]: time="2026-01-27T20:02:38+07:00" level=info msg="zeroconf server listening on port 33221" Jan 27 20:02:38 volumio volumio[14883]: info: CoreCommandRouter::volumioGetState Jan 27 20:02:38 volumio volumio[14883]: info: CorePlayQueue::getTrack 0 Jan 27 20:02:38 volumio volumio[14883]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jan 27 20:02:38 volumio volumio[14883]: SPOTIFY: SPOTIFY VOLUME undefined Jan 27 20:02:38 volumio volumio[14883]: SPOTIFY: VOLUMIO VOLUME 100 Jan 27 20:02:38 volumio volumio[14883]: info: Aligning Spotify Volume to Volumio Volume Jan 27 20:02:38 volumio volumio[14883]: info: CoreCommandRouter::volumioGetState Jan 27 20:02:38 volumio volumio[14883]: info: CorePlayQueue::getTrack 0 Jan 27 20:02:38 volumio volumio[14883]: info: Setting Spotify Volume from Volumio: 100 Jan 27 20:02:38 volumio go-librespot[15254]: time="2026-01-27T20:02:38+07:00" level=debug msg="obtained new client token: AABZDzGVt92p358E/zKUqIzoRCC/748OhS0S+5XtxJNV11txIyfO51ynD2R1Nj4dieoswFEap29tdF+ySuKR6fo17I7vz5QKZyMxeAl9F7a+RC9j79hMh5xeUFZL2TDpIubLB9tgGrLr6V11hHRSJ7ztQfi01m3hNyK2kEflhdI3TfuZsNvxrbkbS/dGfgVEcK8jdodpcz1AgNaru9jXpT9omD9C+WB+ACs0WJSDsEHHlkWtEoFlu3kLv20=" Jan 27 20:02:39 volumio go-librespot[15254]: time="2026-01-27T20:02:39+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 27 20:02:39 volumio go-librespot[15254]: time="2026-01-27T20:02:39+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed performing keyexchange: failed reading APResponseMessage message: failed reading message length: EOF" Jan 27 20:02:39 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 27 20:02:39 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 27 20:02:39 volumio volumio[14883]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 27 20:02:39 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 27 20:02:39 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 27 20:02:39 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 27 20:02:39 volumio volumio[14883]: Error: socket hang up Jan 27 20:02:39 volumio volumio[14883]: at connResetException (node:internal/errors:720:14) Jan 27 20:02:39 volumio volumio[14883]: at Socket.socketOnEnd (node:_http_client:519:23) Jan 27 20:02:39 volumio volumio[14883]: at Socket.emit (node:events:526:35) Jan 27 20:02:39 volumio volumio[14883]: at endReadableNT (node:internal/streams/readable:1376:12) Jan 27 20:02:39 volumio volumio[14883]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Jan 27 20:02:39 volumio volumio[14883]: code: 'ECONNRESET', Jan 27 20:02:39 volumio volumio[14883]: response: undefined Jan 27 20:02:39 volumio volumio[14883]: } Jan 27 20:02:39 volumio volumio[14883]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 27 20:02:40 volumio sudo[15284]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-27 20:01' Jan 27 20:02:40 volumio sudo[15284]: 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"