Jan 28 10:03:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 10:03:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 10:03:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 10:03:01 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 2. Jan 28 10:03:01 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 10:03:01 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 10:03:01 volumio go-librespot[31308]: go-librespot daemon starting... Jan 28 10:03:01 volumio go-librespot[31309]: time="2026-01-28T10:03:01+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 10:03:01 volumio go-librespot[31309]: time="2026-01-28T10:03:01+07:00" level=debug msg="app state loaded" Jan 28 10:03:01 volumio go-librespot[31309]: time="2026-01-28T10:03:01+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 10:03:02 volumio go-librespot[31309]: time="2026-01-28T10:03:02+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 28 10:03:02 volumio go-librespot[31309]: time="2026-01-28T10:03:02+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 28 10:03:02 volumio go-librespot[31309]: time="2026-01-28T10:03:02+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 28 10:03:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 10:03:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 10:03:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 10:03:02 volumio go-librespot[31309]: time="2026-01-28T10:03:02+07:00" level=info msg="zeroconf server listening on port 42785" Jan 28 10:03:02 volumio volumio[30972]: info: Initializing connection to go-librespot Websocket Jan 28 10:03:02 volumio go-librespot[31309]: time="2026-01-28T10:03:02+07:00" level=debug msg="obtained new client token: AADJywfEvOcR/4vXCylLdLWF9LNgLXHjS4z3KmJ527HNtZ6LA3OwKZRGFg/JdVMCjPZME470+vCNwPvAAEwwX2+ZoMzwxHNcHEGh5uHMyxDQ6H8y/Jnx5i2Y35LWW5s1OG8OW8SxkYtIxSrMTErW8l5EZ0Y6aE7GlVRoH7Nu0GMV/E1PQMZDsaGBZ7WjI4VZ8BF/VItoypgKIxb4IrUqvO1enwpN9Jlc4OExYoQZ7FNwqqzno0AuWriEp3Y=" Jan 28 10:03:02 volumio go-librespot[31309]: time="2026-01-28T10:03:02+07:00" level=debug msg="new websocket client" Jan 28 10:03:02 volumio volumio[30972]: info: Connection to go-librespot Websocket established Jan 28 10:03:02 volumio go-librespot[31309]: time="2026-01-28T10:03:02+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 28 10:03:02 volumio go-librespot[31309]: time="2026-01-28T10:03:02+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 28 10:03:02 volumio go-librespot[31309]: time="2026-01-28T10:03:02+07:00" level=debug msg="completed keyexchange" Jan 28 10:03:02 volumio go-librespot[31309]: time="2026-01-28T10:03:02+07:00" level=debug msg="completed challenge" Jan 28 10:03:02 volumio volumio[30972]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 28 10:03:02 volumio go-librespot[31309]: time="2026-01-28T10:03:02+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 10:03:02 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 10:03:02 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 10:03:02 volumio volumio[30972]: info: Connection to go-librespot Websocket closed Jan 28 10:03:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 10:03:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 10:03:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 10:03:05 volumio volumio[30972]: info: Getting Spotify volume Jan 28 10:03:05 volumio volumio[30972]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 10:03:05 volumio volumio[30972]: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 10:03:05 volumio volumio[30972]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Jan 28 10:03:05 volumio volumio[30972]: errno: -111, Jan 28 10:03:05 volumio volumio[30972]: code: 'ECONNREFUSED', Jan 28 10:03:05 volumio volumio[30972]: syscall: 'connect', Jan 28 10:03:05 volumio volumio[30972]: address: '127.0.0.1', Jan 28 10:03:05 volumio volumio[30972]: port: 9879, Jan 28 10:03:05 volumio volumio[30972]: response: undefined Jan 28 10:03:05 volumio volumio[30972]: } Jan 28 10:03:05 volumio volumio[30972]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 10:03:05 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 3. Jan 28 10:03:05 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 10:03:06 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 10:03:06 volumio go-librespot[31328]: go-librespot daemon starting... Jan 28 10:03:06 volumio go-librespot[31329]: time="2026-01-28T10:03:06+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 10:03:06 volumio go-librespot[31329]: time="2026-01-28T10:03:06+07:00" level=debug msg="app state loaded" Jan 28 10:03:06 volumio go-librespot[31329]: time="2026-01-28T10:03:06+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 10:03:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 10:03:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 10:03:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 10:03:06 volumio go-librespot[31329]: time="2026-01-28T10:03:06+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew1.spotify.com:80]" Jan 28 10:03:06 volumio go-librespot[31329]: time="2026-01-28T10:03:06+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 28 10:03:06 volumio go-librespot[31329]: time="2026-01-28T10:03:06+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 28 10:03:06 volumio go-librespot[31329]: time="2026-01-28T10:03:06+07:00" level=info msg="zeroconf server listening on port 44903" Jan 28 10:03:06 volumio go-librespot[31329]: time="2026-01-28T10:03:06+07:00" level=debug msg="obtained new client token: AAAxgOqa4q7kbKbhjXrkVW/EvYUsBzOictOLJ37PwwU/7FAZZxvFbBpG9ScvhJMEQLD5B32Mw20JO+4RJ7LeVlednSKTI7DWRtla2icDwbFZZAzD0yTPYly5YxP0XhMgLdTvjOUfmEN4TpEVbrvqXc+xPTyV/7Ckm4aKT2KRt1+nVRKQLh+czC1BdcAsI19xd0lvOVQRgZxX7mE8ArcCxdNHidp21wgp1/oU99PO0hNGrVJnOdsfJg+1/mo=" Jan 28 10:03:07 volumio go-librespot[31329]: time="2026-01-28T10:03:07+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 10:03:07 volumio sudo[31354]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-28 10:02' Jan 28 10:03:07 volumio sudo[31354]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 10:03:07 volumio go-librespot[31329]: time="2026-01-28T10:03:07+07:00" level=debug msg="completed keyexchange" Jan 28 10:03:07 volumio go-librespot[31329]: time="2026-01-28T10:03:07+07:00" level=debug msg="completed challenge" Jan 28 10:03:07 volumio go-librespot[31329]: time="2026-01-28T10:03:07+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 28 10:03:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 10:03:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 10:03:07 volumio sudo[31354]: pam_unix(sudo:session): session closed for user root Jan 28 10:03:07 volumio volumio-remote-updater[628]: [2026-01-28 10:03:07] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Jan 28 10:03:07 volumio volumio-remote-updater[628]: [2026-01-28 10:03:07] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Jan 28 10:03:07 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 28 10:03:07 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 28 10:03:07 volumio systemd[1]: volumio.service: Consumed 53.027s CPU time. Jan 28 10:03:07 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 28 10:03:07 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 28 10:03:07 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 9955. Jan 28 10:03:07 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 28 10:03:07 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Jan 28 10:03:07 volumio systemd[1]: volumio.service: Consumed 53.027s CPU time. Jan 28 10:03:07 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Jan 28 10:03:07 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 28 10:03:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 10:03:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 10:03:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 10:03:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 10:03:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 10:03:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 10:03:10 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 4. Jan 28 10:03:10 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 10:03:10 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 10:03:10 volumio go-librespot[31382]: go-librespot daemon starting... Jan 28 10:03:10 volumio go-librespot[31383]: time="2026-01-28T10:03:10+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 10:03:10 volumio go-librespot[31383]: time="2026-01-28T10:03:10+07:00" level=debug msg="app state loaded" Jan 28 10:03:10 volumio go-librespot[31383]: time="2026-01-28T10:03:10+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 10:03:11 volumio go-librespot[31383]: time="2026-01-28T10:03:11+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 10:03:11 volumio go-librespot[31383]: time="2026-01-28T10:03:11+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 28 10:03:11 volumio go-librespot[31383]: time="2026-01-28T10:03:11+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 28 10:03:11 volumio go-librespot[31383]: time="2026-01-28T10:03:11+07:00" level=info msg="zeroconf server listening on port 39811" Jan 28 10:03:11 volumio volumio[31367]: info: ------------------------------------------- Jan 28 10:03:11 volumio volumio[31367]: info: ----- Volumio3 ---- Jan 28 10:03:11 volumio volumio[31367]: info: ------------------------------------------- Jan 28 10:03:11 volumio volumio[31367]: info: ----- System startup ---- Jan 28 10:03:11 volumio go-librespot[31383]: time="2026-01-28T10:03:11+07:00" level=debug msg="obtained new client token: AAB/a2EvqXJwygAvpYXC97E81VHD9asJv0p98obKF1amhbyQxarphccfKAUrRaeVDqK7rYDmZzxWUNe0DRDveDkX6ttgEM4YM4dZGeB1QldBs1owUeWj/el3+mNZI75VA/1dxfKpKOIfUgqfjSm2HNux+tdO9pWT7Al8utU0xA6Uc76UoRBFAtTnsDkNQXIJxeW1txuR8sWn/eA2faDJ+dGhajZ1utPEVsToOFvIWyUDYF6ScWwvVCwIw0M=" Jan 28 10:03:11 volumio volumio[31367]: info: ------------------------------------------- Jan 28 10:03:11 volumio go-librespot[31383]: time="2026-01-28T10:03:11+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 10:03:11 volumio go-librespot[31383]: time="2026-01-28T10:03:11+07:00" level=debug msg="completed keyexchange" Jan 28 10:03:11 volumio go-librespot[31383]: time="2026-01-28T10:03:11+07:00" level=debug msg="completed challenge" Jan 28 10:03:11 volumio go-librespot[31383]: time="2026-01-28T10:03:11+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 28 10:03:11 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 10:03:11 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 10:03:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 10:03:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 10:03:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 10:03:12 volumio volumio-remote-updater[628]: [2026-01-28 10:03:12] [connect] Successful connection Jan 28 10:03:12 volumio volumio[31367]: info: MYVOLUMIO Environment detected Jan 28 10:03:12 volumio volumio[31367]: info: Plugin folders cleanup Jan 28 10:03:12 volumio volumio[31367]: info: Scanning into folder /volumio/app/plugins/ Jan 28 10:03:12 volumio volumio[31367]: info: Scanning category audio_interface Jan 28 10:03:13 volumio volumio[31367]: info: Scanning category miscellanea Jan 28 10:03:13 volumio volumio[31367]: info: Scanning category music_service Jan 28 10:03:13 volumio volumio[31367]: info: Scanning category plugins.json Jan 28 10:03:13 volumio volumio[31367]: info: Scanning category system_controller Jan 28 10:03:13 volumio volumio[31367]: info: Scanning category user_interface Jan 28 10:03:13 volumio volumio[31367]: info: Scanning into folder /data/plugins/ Jan 28 10:03:13 volumio volumio[31367]: info: Scanning category music_service Jan 28 10:03:13 volumio volumio[31367]: info: Plugin folders cleanup completed Jan 28 10:03:13 volumio volumio[31367]: info: ------------------------------------------- Jan 28 10:03:13 volumio volumio[31367]: info: ----- Core plugins startup ---- Jan 28 10:03:13 volumio volumio[31367]: info: ------------------------------------------- Jan 28 10:03:13 volumio volumio[31367]: info: Loading plugins from folder /volumio/app/plugins/ Jan 28 10:03:13 volumio volumio[31367]: info: Adding plugin upnp to MyMusic Plugins Jan 28 10:03:13 volumio volumio[31367]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 28 10:03:13 volumio volumio[31367]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 28 10:03:13 volumio volumio[31367]: info: Loading plugins from folder /data/plugins/ Jan 28 10:03:13 volumio volumio[31367]: info: Loading plugin "system"... Jan 28 10:03:13 volumio volumio[31367]: info: Loading plugin "appearance"... Jan 28 10:03:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 10:03:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 10:03:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 10:03:14 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 5. Jan 28 10:03:14 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 10:03:14 volumio volumio[31367]: info: Loading plugin "network"... Jan 28 10:03:15 volumio volumio[31367]: info: Refreshing Cached IP Addresses Jan 28 10:03:15 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 10:03:15 volumio go-librespot[31403]: go-librespot daemon starting... Jan 28 10:03:15 volumio sudo[31405]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 28 10:03:15 volumio sudo[31405]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 10:03:15 volumio sudo[31407]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 28 10:03:15 volumio sudo[31407]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 10:03:15 volumio volumio[31367]: info: Loading plugin "services"... Jan 28 10:03:15 volumio go-librespot[31410]: time="2026-01-28T10:03:15+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 10:03:15 volumio go-librespot[31410]: time="2026-01-28T10:03:15+07:00" level=debug msg="app state loaded" Jan 28 10:03:15 volumio sudo[31405]: pam_unix(sudo:session): session closed for user root Jan 28 10:03:15 volumio go-librespot[31410]: time="2026-01-28T10:03:15+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 10:03:15 volumio sudo[31407]: pam_unix(sudo:session): session closed for user root Jan 28 10:03:15 volumio volumio[31367]: info: Loading plugin "alsa_controller"... Jan 28 10:03:15 volumio sudo[31415]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 28 10:03:15 volumio sudo[31415]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 10:03:15 volumio volumio[31367]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 10:03:15 volumio volumio[31367]: info: Loading plugin "wizard"... Jan 28 10:03:15 volumio volumio[31367]: info: Loading plugin "networkfs"... Jan 28 10:03:15 volumio volumio[31367]: info: Starting Udev Watcher for removable devices Jan 28 10:03:15 volumio volumio[31367]: info: Ignoring mount for partition: boot Jan 28 10:03:15 volumio volumio[31367]: info: Ignoring mount for partition: volumio Jan 28 10:03:15 volumio volumio[31367]: info: Ignoring mount for partition: volumio_data Jan 28 10:03:15 volumio volumio[31367]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 10:03:15 volumio volumio[31367]: info: Loading plugin "volumio_command_line_client"... Jan 28 10:03:15 volumio volumio[31367]: info: Loading plugin "upnp"... Jan 28 10:03:15 volumio volumio[31367]: info: [1769569395479] Starting Upmpd Daemon Jan 28 10:03:15 volumio volumio[31367]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 10:03:15 volumio volumio[31367]: info: Loading plugin "my_music"... Jan 28 10:03:15 volumio volumio[31367]: info: Loading plugin "mpd"... Jan 28 10:03:15 volumio go-librespot[31410]: time="2026-01-28T10:03:15+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 28 10:03:15 volumio go-librespot[31410]: time="2026-01-28T10:03:15+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 28 10:03:15 volumio go-librespot[31410]: time="2026-01-28T10:03:15+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 28 10:03:15 volumio go-librespot[31410]: time="2026-01-28T10:03:15+07:00" level=info msg="zeroconf server listening on port 46671" Jan 28 10:03:15 volumio go-librespot[31410]: time="2026-01-28T10:03:15+07:00" level=debug msg="obtained new client token: AAC0+gMmZRTjfeA/zwZqdhBpQNoi9NK4ELfqBwPL3MF1OgnftiMJhEcNW17GuMbWRTp89/1IJXMKiHG/GVCVfiiGjKS2iVS6eX3SOyHsQMcpoNUCjk5mqwa8AfiGOcBC4ZoNykuWdb/YqpuXHAKO7Wt0zLjrg2KzQEiYlz8M/tDlMy4D04QF6eQuqotqJPeNHl2BBz5YgXGp8qlO1CtqydErsEo+I3hsLkpPyr5eTM3bM1AhsT5sApbgU3g=" Jan 28 10:03:16 volumio go-librespot[31410]: time="2026-01-28T10:03:16+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 10:03:16 volumio volumio[31367]: info: Loading plugin "upnp_browser"... Jan 28 10:03:16 volumio go-librespot[31410]: time="2026-01-28T10:03:16+07:00" level=debug msg="completed keyexchange" Jan 28 10:03:16 volumio go-librespot[31410]: time="2026-01-28T10:03:16+07:00" level=debug msg="completed challenge" Jan 28 10:03:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 10:03:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 10:03:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 10:03:16 volumio go-librespot[31410]: time="2026-01-28T10:03:16+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 10:03:16 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 10:03:16 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 10:03:18 volumio sudo[31415]: pam_unix(sudo:session): session closed for user root Jan 28 10:03:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 10:03:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 10:03:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 10:03:19 volumio volumio[31367]: info: Starting UPNP Browser Jan 28 10:03:19 volumio volumio[31367]: info: Loading plugin "alarm-clock"... Jan 28 10:03:19 volumio volumio[31367]: info: Loading plugin "airplay_emulation"... Jan 28 10:03:19 volumio volumio[31367]: info: Starting Shairport Sync Jan 28 10:03:19 volumio volumio[31367]: info: Loading plugin "last_100"... Jan 28 10:03:19 volumio volumio[31367]: info: Loading plugin "webradio"... Jan 28 10:03:19 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 6. Jan 28 10:03:19 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 10:03:19 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 10:03:19 volumio go-librespot[31446]: go-librespot daemon starting... Jan 28 10:03:19 volumio go-librespot[31447]: time="2026-01-28T10:03:19+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 10:03:19 volumio go-librespot[31447]: time="2026-01-28T10:03:19+07:00" level=debug msg="app state loaded" Jan 28 10:03:19 volumio go-librespot[31447]: time="2026-01-28T10:03:19+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 10:03:19 volumio volumio[31367]: info: Loading plugin "i2s_dacs"... Jan 28 10:03:19 volumio volumio[31367]: info: Loading plugin "volumiodiscovery"... Jan 28 10:03:19 volumio volumio[31367]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 28 10:03:19 volumio volumio[31367]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 10:03:19 volumio volumio[31367]: *** WARNING *** For more information see Jan 28 10:03:19 volumio volumio[31367]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 28 10:03:19 volumio volumio[31367]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 10:03:19 volumio volumio[31367]: *** WARNING *** For more information see Jan 28 10:03:19 volumio node[31367]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 28 10:03:19 volumio node[31367]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 10:03:19 volumio node[31367]: *** WARNING *** For more information see Jan 28 10:03:19 volumio node[31367]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 28 10:03:19 volumio node[31367]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 10:03:19 volumio node[31367]: *** WARNING *** For more information see Jan 28 10:03:19 volumio volumio[31367]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 28 10:03:19 volumio volumio[31367]: info: Discovery: Started advertising with name: Volumio Jan 28 10:03:19 volumio volumio[31367]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 10:03:19 volumio volumio[31367]: info: Loading plugin "spop"... Jan 28 10:03:20 volumio go-librespot[31447]: time="2026-01-28T10:03: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-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 10:03:20 volumio go-librespot[31447]: time="2026-01-28T10:03:20+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 28 10:03:20 volumio go-librespot[31447]: time="2026-01-28T10:03:20+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 28 10:03:20 volumio go-librespot[31447]: time="2026-01-28T10:03:20+07:00" level=info msg="zeroconf server listening on port 39093" Jan 28 10:03:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 10:03:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 10:03:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 10:03:20 volumio go-librespot[31447]: time="2026-01-28T10:03:20+07:00" level=debug msg="obtained new client token: AABwjLR2RXYA1vrN+DJVkWTmiOKTZmq4JrsVuvjmpvdzGOougX4Z+z6HF1spixTgWrg7s3fFTbshRU4WtAbn/cPpE9pdBBl9/OONC/fI+NUbAWE7xEXAgUURwn03t1R2LPHDwjA0keETu2oR/sT/Utl02pvAoQuIaRzPRWvlPjl2azHAaCTydqvd3TAoYjep64sUuY6BSp5zAcSH8+rW2R14ExCDTCg6jEVf5ynXEURsIOa9EcwZjzGqc/8=" Jan 28 10:03:20 volumio go-librespot[31447]: time="2026-01-28T10:03:20+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 10:03:20 volumio go-librespot[31447]: time="2026-01-28T10:03:20+07:00" level=debug msg="completed keyexchange" Jan 28 10:03:20 volumio go-librespot[31447]: time="2026-01-28T10:03:20+07:00" level=debug msg="completed challenge" Jan 28 10:03:20 volumio go-librespot[31447]: time="2026-01-28T10:03:20+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 28 10:03:20 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 10:03:20 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 10:03:21 volumio volumio[31367]: info: Loading plugin "ytcr"... Jan 28 10:03:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 10:03:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 10:03:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 10:03:23 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 7. Jan 28 10:03:23 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 10:03:23 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 10:03:23 volumio go-librespot[31456]: go-librespot daemon starting... Jan 28 10:03:23 volumio go-librespot[31457]: time="2026-01-28T10:03:23+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 10:03:23 volumio go-librespot[31457]: time="2026-01-28T10:03:23+07:00" level=debug msg="app state loaded" Jan 28 10:03:23 volumio go-librespot[31457]: time="2026-01-28T10:03:23+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 10:03:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 10:03:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 10:03:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 10:03:24 volumio go-librespot[31457]: time="2026-01-28T10:03:24+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 10:03:24 volumio go-librespot[31457]: time="2026-01-28T10:03:24+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 28 10:03:24 volumio go-librespot[31457]: time="2026-01-28T10:03:24+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 28 10:03:24 volumio go-librespot[31457]: time="2026-01-28T10:03:24+07:00" level=info msg="zeroconf server listening on port 33037" Jan 28 10:03:24 volumio volumio[31367]: info: Loading plugin "ytmusic"... Jan 28 10:03:24 volumio go-librespot[31457]: time="2026-01-28T10:03:24+07:00" level=debug msg="obtained new client token: AACYUZ7FJL91riBtoLYBt9kKAWG9pJnluoWJTB6BthkzepkLwH+nGogJtPmnhlPy2b77PTmpaGfW2bj1MqW8o5t7saOOVsnanTdD+ysOBU+TxEsRM173nUqqz4+3vDZtsGWJNo7uMn4zNZIs8v8gaU1q36Aw0W0zCRt03mHbttDSWLmZUstNhWMcTUQysSJ0XUoV1QHD1r3Xo/SgbPZHuMrTWkj/xRfLpophwmQIlZeyY3fZo89AmnqZcWQ=" Jan 28 10:03:24 volumio go-librespot[31457]: time="2026-01-28T10:03:24+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 10:03:24 volumio go-librespot[31457]: time="2026-01-28T10:03:24+07:00" level=debug msg="completed keyexchange" Jan 28 10:03:24 volumio go-librespot[31457]: time="2026-01-28T10:03:24+07:00" level=debug msg="completed challenge" Jan 28 10:03:24 volumio go-librespot[31457]: time="2026-01-28T10:03:24+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 28 10:03:24 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 10:03:24 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 10:03:25 volumio volumio-remote-updater[628]: [2026-01-28 10:03:25] [connect] Successful connection Jan 28 10:03:25 volumio volumio[31367]: info: Loading plugin "outputs"... Jan 28 10:03:25 volumio volumio[31367]: info: Loading plugin "albumart"... Jan 28 10:03:25 volumio volumio[31367]: info: Plugin example_plugin is not enabled Jan 28 10:03:25 volumio volumio[31367]: info: Loading plugin "inputs"... Jan 28 10:03:25 volumio volumio[31367]: info: Loading plugin "updater_comm"... Jan 28 10:03:25 volumio volumio[31367]: info: Plugin mpdemulation is not enabled Jan 28 10:03:25 volumio volumio[31367]: info: Loading plugin "rest_api"... Jan 28 10:03:25 volumio volumio[31367]: info: Loading plugin "websocket"... Jan 28 10:03:25 volumio volumio[31367]: info: Starting Socket.io Server version 1.7.4 Jan 28 10:03:25 volumio volumio[31367]: info: Loading plugin "RoonBridge"... Jan 28 10:03:26 volumio volumio[31367]: info: Applying required configuration parameters for plugin RoonBridge Jan 28 10:03:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 10:03:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 10:03:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 10:03:26 volumio volumio[31367]: info: Loading i18n strings for locale en Jan 28 10:03:26 volumio volumio[31367]: Updating browse sources language Jan 28 10:03:26 volumio volumio[31367]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 10:03:26 volumio volumio[31367]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 10:03:26 volumio volumio[31367]: info: CoreCommandRouter::initPlayerControls Jan 28 10:03:26 volumio volumio[31367]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 10:03:26 volumio volumio[31367]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 10:03:26 volumio volumio[31367]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 10:03:26 volumio volumio[31367]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 10:03:26 volumio volumio[31367]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 10:03:26 volumio volumio[31367]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 10:03:26 volumio volumio[31367]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 10:03:26 volumio volumio[31367]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 10:03:26 volumio volumio[31367]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 10:03:26 volumio volumio[31367]: Express server listening on port 3000 Jan 28 10:03:26 volumio volumio[31367]: [Metrics] WebUI: 16s 145.42ms Jan 28 10:03:26 volumio volumio[31479]: Forking 3 albumart workers Jan 28 10:03:26 volumio volumio[31367]: info: CoreStateMachine::resetVolumioState Jan 28 10:03:26 volumio volumio[31367]: info: CoreStateMachine::getcurrentVolume Jan 28 10:03:26 volumio volumio[31367]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 10:03:26 volumio sudo[31507]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 28 10:03:26 volumio sudo[31507]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 10:03:26 volumio sudo[31507]: pam_unix(sudo:session): session closed for user root Jan 28 10:03:26 volumio sudo[31518]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 28 10:03:26 volumio sudo[31518]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 10:03:26 volumio sudo[31518]: pam_unix(sudo:session): session closed for user root Jan 28 10:03:26 volumio volumio[31367]: info: Volumio Network Manager: Network status updated: 1 Jan 28 10:03:27 volumio volumio-remote-updater[628]: [2026-01-28 10:03:27] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1769569405 101 Jan 28 10:03:27 volumio volumio[31367]: 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 28 10:03:27 volumio volumio[31367]: info: VolumeController:: Volume=100 Mute =false Jan 28 10:03:27 volumio volumio[31367]: info: CoreStateMachine::pushState Jan 28 10:03:27 volumio volumio[31367]: info: CorePlayQueue::getTrack 0 Jan 28 10:03:27 volumio volumio[31367]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 10:03:27 volumio volumio[31367]: info: CoreCommandRouter::volumioPushState Jan 28 10:03:27 volumio volumio[31367]: info: CoreStateMachine::updateTrackBlock Jan 28 10:03:27 volumio volumio[31367]: info: CorePlayQueue::getTrackBlock Jan 28 10:03:27 volumio volumio[31367]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 10:03:27 volumio volumio[31367]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 10:03:27 volumio volumio[31367]: info: Reloading queue from file Jan 28 10:03:27 volumio volumio[31367]: info: CoreStateMachine::setRepeat null single undefined Jan 28 10:03:27 volumio volumio[31367]: info: CoreStateMachine::pushState Jan 28 10:03:27 volumio volumio[31367]: info: CorePlayQueue::getTrack 0 Jan 28 10:03:27 volumio volumio[31367]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 10:03:27 volumio volumio[31367]: info: CoreCommandRouter::volumioPushState Jan 28 10:03:27 volumio volumio[31367]: info: CoreStateMachine::setRandom null Jan 28 10:03:27 volumio volumio[31367]: info: CoreStateMachine::pushState Jan 28 10:03:27 volumio volumio[31367]: info: CorePlayQueue::getTrack 0 Jan 28 10:03:27 volumio volumio[31367]: info: CoreCommandRouter::volumioPushState Jan 28 10:03:27 volumio volumio[31367]: info: Setting Device type: Raspberry PI Jan 28 10:03:27 volumio volumio[31367]: info: Completed loading Core Plugins Jan 28 10:03:27 volumio volumio[31367]: info: Preparing to generate the ALSA configuration file Jan 28 10:03:27 volumio volumio[31367]: info: VolumeController:: Volume=100 Mute =false Jan 28 10:03:27 volumio volumio[31367]: info: CoreStateMachine::pushState Jan 28 10:03:27 volumio volumio[31367]: info: CorePlayQueue::getTrack 0 Jan 28 10:03:27 volumio volumio[31367]: info: CoreCommandRouter::volumioPushState Jan 28 10:03:27 volumio volumio[31367]: info: Asound.conf file unchanged, so no further update is needed Jan 28 10:03:27 volumio volumio[31367]: info: Output device has changed, restarting MPD Jan 28 10:03:27 volumio sudo[31539]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 28 10:03:27 volumio sudo[31539]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 10:03:27 volumio volumio[31367]: info: Output device has changed, restarting Shairport Sync Jan 28 10:03:27 volumio volumio[31367]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 10:03:27 volumio volumio[31367]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 10:03:27 volumio sudo[31542]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 28 10:03:27 volumio sudo[31542]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 10:03:27 volumio sudo[31542]: pam_unix(sudo:session): session closed for user root Jan 28 10:03:27 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 8. Jan 28 10:03:27 volumio volumio[31367]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 10:03:27 volumio volumio[31367]: info: ___________ START PLUGINS ___________ Jan 28 10:03:27 volumio sudo[31544]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 28 10:03:27 volumio sudo[31544]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 10:03:27 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 10:03:27 volumio volumio[31367]: info: ControllerMpd::onStart: Initializing MPD Jan 28 10:03:27 volumio volumio[31367]: info: Creating MPD Configuration file Jan 28 10:03:27 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 10:03:28 volumio go-librespot[31551]: go-librespot daemon starting... Jan 28 10:03:28 volumio volumio[31367]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 10:03:28 volumio volumio[31367]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 10:03:28 volumio volumio[31367]: info: [1769569408023] CoreMusicLibrary::Adding element Media Servers Jan 28 10:03:28 volumio volumio[31367]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 10:03:28 volumio go-librespot[31555]: time="2026-01-28T10:03:28+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 10:03:28 volumio go-librespot[31555]: time="2026-01-28T10:03:28+07:00" level=debug msg="app state loaded" Jan 28 10:03:28 volumio sudo[31539]: pam_unix(sudo:session): session closed for user root Jan 28 10:03:28 volumio go-librespot[31555]: time="2026-01-28T10:03:28+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 10:03:28 volumio volumio[31367]: info: UPNP Browser: Client initialized successfully Jan 28 10:03:28 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 28 10:03:28 volumio sudo[31556]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 28 10:03:28 volumio sudo[31556]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 10:03:28 volumio sudo[31553]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 28 10:03:28 volumio sudo[31553]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 10:03:28 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 28 10:03:28 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 28 10:03:28 volumio systemd[1]: mpd.service: Consumed 7.471s CPU time. Jan 28 10:03:28 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 28 10:03:28 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 28 10:03:28 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 28 10:03:28 volumio volumio[31367]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 10:03:28 volumio volumio[31367]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 10:03:28 volumio sudo[31553]: pam_unix(sudo:session): session closed for user root Jan 28 10:03:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 10:03:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 10:03:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 10:03:28 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 28 10:03:28 volumio volumio[31367]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 10:03:28 volumio volumio[31367]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 10:03:28 volumio volumio[31367]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 10:03:28 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 28 10:03:28 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 28 10:03:28 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 28 10:03:28 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 28 10:03:28 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 28 10:03:28 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 28 10:03:28 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 28 10:03:28 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 28 10:03:28 volumio volumio[31367]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 10:03:28 volumio volumio[31367]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 10:03:28 volumio volumio[31367]: info: [1769569408604] CoreMusicLibrary::Adding element Last_100 Jan 28 10:03:28 volumio volumio[31367]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 10:03:28 volumio volumio[31367]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 10:03:28 volumio volumio[31367]: info: [1769569408644] CoreMusicLibrary::Adding element Webradio Jan 28 10:03:28 volumio volumio[31367]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 10:03:28 volumio volumio[31367]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 10:03:28 volumio volumio[31367]: info: Initializing BBC Radios Jan 28 10:03:28 volumio go-librespot[31555]: time="2026-01-28T10:03:28+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 28 10:03:28 volumio go-librespot[31555]: time="2026-01-28T10:03:28+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 28 10:03:28 volumio go-librespot[31555]: time="2026-01-28T10:03:28+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 28 10:03:28 volumio go-librespot[31555]: time="2026-01-28T10:03:28+07:00" level=info msg="zeroconf server listening on port 41773" Jan 28 10:03:28 volumio volumio[31367]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 10:03:28 volumio volumio[31367]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 10:03:28 volumio volumio[31367]: info: Creating Spotify config file Jan 28 10:03:28 volumio volumio[31367]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 10:03:29 volumio go-librespot[31555]: time="2026-01-28T10:03:29+07:00" level=debug msg="obtained new client token: AAAeuJ9nlWnOzZIutJknzYMJ5ed9aa4XskHfTtyVH0Hs5zJW2JLtxDO5Zsr2N51EbVCiDw8bGX/dz9STQvWOcUODAog0C0u1z6hqz8fg0Hb2VDim1UyfadgxO103CsUvUj/L42C5axnzAfw2cI5cicf6giq9urrOF25572cJI+XDPb+fdri9fRHeWshkXtzRW+rmyFflTVfMSTJ9+XaBsuMRMDFZeCimDMrCshYeupmUdiKQfIiMXh68Zs4=" Jan 28 10:03:29 volumio sudo[31577]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 28 10:03:29 volumio sudo[31577]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 28 10:03:29 volumio sudo[31577]: pam_unix(sudo:session): session closed for user root Jan 28 10:03:29 volumio go-librespot[31555]: time="2026-01-28T10:03:29+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 10:03:29 volumio go-librespot[31555]: time="2026-01-28T10:03:29+07:00" level=debug msg="completed keyexchange" Jan 28 10:03:29 volumio go-librespot[31555]: time="2026-01-28T10:03:29+07:00" level=debug msg="completed challenge" Jan 28 10:03:29 volumio go-librespot[31555]: time="2026-01-28T10:03:29+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 10:03:29 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 10:03:29 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 10:03:30 volumio volumio[31367]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 10:03:30 volumio volumio[31367]: info: [1769569410045] CoreMusicLibrary::Adding element YouTube Music Jan 28 10:03:30 volumio volumio[31367]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 10:03:30 volumio volumio[31367]: Cannot find translation for source YouTube Music Jan 28 10:03:30 volumio volumio[31367]: info: Volumio Calling Home Jan 28 10:03:30 volumio volumio[31495]: Starting albumart workers Jan 28 10:03:30 volumio sudo[31595]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Jan 28 10:03:30 volumio sudo[31595]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 10:03:30 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 10:03:30 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 10:03:30 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 10:03:30 volumio volumio[31492]: Starting albumart workers Jan 28 10:03:30 volumio sudo[31595]: pam_unix(sudo:session): session closed for user root Jan 28 10:03:30 volumio volumio[31494]: Starting albumart workers Jan 28 10:03:30 volumio volumio[31367]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Jan 28 10:03:30 volumio volumio[31367]: info: Discovery: Found device Volumio Jan 28 10:03:30 volumio volumio[31367]: info: CoreCommandRouter::volumioGetState Jan 28 10:03:30 volumio volumio[31367]: info: CorePlayQueue::getTrack 0 Jan 28 10:03:30 volumio volumio[31367]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Jan 28 10:03:30 volumio volumio[31367]: info: Discovery: Found device Volumio Jan 28 10:03:30 volumio volumio[31367]: info: CoreCommandRouter::volumioGetState Jan 28 10:03:30 volumio volumio[31367]: info: CorePlayQueue::getTrack 0 Jan 28 10:03:30 volumio volumio[31367]: info: MPD Permissions set Jan 28 10:03:30 volumio volumio[31367]: info: MPD Permissions set Jan 28 10:03:30 volumio volumio[31367]: info: Upmpdcli Daemon Started Jan 28 10:03:31 volumio volumio[31367]: info: Spotify config file written Jan 28 10:03:31 volumio volumio[31367]: 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 28 10:03:31 volumio volumio[31367]: info: Volumio called home Jan 28 10:03:31 volumio sudo[31601]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 28 10:03:31 volumio sudo[31601]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 10:03:31 volumio volumio[31367]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 10:03:31 volumio volumio[31367]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 10:03:31 volumio volumio[31367]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 10:03:31 volumio volumio[31367]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 10:03:31 volumio volumio[31367]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 10:03:31 volumio volumio[31367]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 10:03:31 volumio volumio[31367]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 10:03:31 volumio volumio[31367]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 10:03:31 volumio volumio[31367]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 10:03:31 volumio volumio[31367]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 10:03:31 volumio volumio[31367]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 10:03:31 volumio volumio[31367]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 10:03:31 volumio volumio[31367]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 10:03:31 volumio volumio[31367]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 10:03:31 volumio volumio[31367]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 10:03:31 volumio volumio[31367]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 10:03:31 volumio volumio[31367]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 10:03:31 volumio volumio[31367]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 10:03:31 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 10:03:31 volumio volumio[31367]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 10:03:31 volumio volumio[31367]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 10:03:31 volumio volumio[31367]: info: No need to fix Spotify hosts Jan 28 10:03:31 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 10:03:31 volumio go-librespot[31610]: go-librespot daemon starting... Jan 28 10:03:31 volumio sudo[31601]: pam_unix(sudo:session): session closed for user root Jan 28 10:03:31 volumio go-librespot[31614]: time="2026-01-28T10:03:31+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 10:03:31 volumio go-librespot[31614]: time="2026-01-28T10:03:31+07:00" level=debug msg="app state loaded" Jan 28 10:03:31 volumio go-librespot[31614]: time="2026-01-28T10:03:31+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 10:03:32 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 10:03:32 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 10:03:32 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 10:03:32 volumio go-librespot[31614]: time="2026-01-28T10:03:32+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 28 10:03:32 volumio go-librespot[31614]: time="2026-01-28T10:03:32+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 28 10:03:32 volumio go-librespot[31614]: time="2026-01-28T10:03:32+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 28 10:03:32 volumio go-librespot[31614]: time="2026-01-28T10:03:32+07:00" level=info msg="zeroconf server listening on port 44809" Jan 28 10:03:32 volumio go-librespot[31614]: time="2026-01-28T10:03:32+07:00" level=debug msg="obtained new client token: AADwSF91Fut5wjlBG0YN3W3FJv0CVYKJJRVdqaU/XTqzGG2/uqe4n19UroFGZa3339R40s0ckSXQ8ceay/mkE08NylYaLChoU+cHFrmSuq0j7IqivY/ZfVvq5KHRBrog0/3f0dfWvcVmMuaCsGadDPkSormCrhw6uXzBhlM6St0xlDGnexY/sMLGhUYUkXD+OGtue1TNynWy4dO2QMlQhG4kMGY6RQ2tgUA6LL8qXniTkamkOaGE5ufTXYw=" Jan 28 10:03:32 volumio go-librespot[31614]: time="2026-01-28T10:03:32+07:00" level=warning msg="failed to connect to AP ap-gae2.spotify.com:4070, retrying with a different AP" error="dial tcp 104.199.241.202:4070: connect: connection refused" Jan 28 10:03:32 volumio go-librespot[31614]: time="2026-01-28T10:03:32+07:00" level=debug msg="connected to ap-gae2.spotify.com:443" Jan 28 10:03:32 volumio volumio[31367]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 28 10:03:32 volumio volumio[31367]: SPOTIFY: BQA5lRIO4Akc87sm3CniPPX3AoZfXl1cA2y9qAamjvP1zsHGqRBcyE6Ds0MfZqTVkIJN75rvzSUlLo5qWCZQTDHfkFGjQooT4Mh8UehLrPaRBYRO_m3_jnh25uXHnqhawZ540Y4eAIiEEgRb0tGkDmst5fsdgy6AQcqq-kepzXHO7w84lezwc6wD6r7CjsrWIpN1R77Zu0GkiX3wuuEGc1N8Oq7vHg1_RDhs418BwEmoTl_kzkCraDuQrOFNwHbkiY0pTHmmwcW5fGW6nXmv5EDwda9rcqygXdpzssEWhAtx8-Otqp8UhR4Z Jan 28 10:03:32 volumio volumio[31367]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 28 10:03:32 volumio volumio[31367]: info: New Spotify access token = BQA5lRIO4Akc87sm3CniPPX3AoZfXl1cA2y9qAamjvP1zsHGqRBcyE6Ds0MfZqTVkIJN75rvzSUlLo5qWCZQTDHfkFGjQooT4Mh8UehLrPaRBYRO_m3_jnh25uXHnqhawZ540Y4eAIiEEgRb0tGkDmst5fsdgy6AQcqq-kepzXHO7w84lezwc6wD6r7CjsrWIpN1R77Zu0GkiX3wuuEGc1N8Oq7vHg1_RDhs418BwEmoTl_kzkCraDuQrOFNwHbkiY0pTHmmwcW5fGW6nXmv5EDwda9rcqygXdpzssEWhAtx8-Otqp8UhR4Z Jan 28 10:03:32 volumio volumio[31367]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 28 10:03:32 volumio volumio[31367]: info: Starting Shairport Sync Jan 28 10:03:32 volumio go-librespot[31614]: time="2026-01-28T10:03:32+07:00" level=debug msg="completed keyexchange" Jan 28 10:03:32 volumio go-librespot[31614]: time="2026-01-28T10:03:32+07:00" level=debug msg="completed challenge" Jan 28 10:03:32 volumio volumio[31367]: info: Starting Shairport Sync Jan 28 10:03:32 volumio volumio[31367]: info: Starting Shairport Sync Jan 28 10:03:33 volumio sudo[31641]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 10:03:33 volumio sudo[31641]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 10:03:33 volumio go-librespot[31614]: time="2026-01-28T10:03:33+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 10:03:33 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 10:03:33 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 10:03:33 volumio sudo[31643]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 10:03:33 volumio sudo[31643]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 10:03:33 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 28 10:03:33 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 28 10:03:33 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 10:03:33 volumio systemd[1]: shairport-sync.service: Consumed 2.281s CPU time. Jan 28 10:03:33 volumio sudo[31645]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 10:03:33 volumio sudo[31645]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 10:03:33 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 10:03:33 volumio sudo[31641]: pam_unix(sudo:session): session closed for user root Jan 28 10:03:33 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 28 10:03:33 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 28 10:03:33 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 10:03:33 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 10:03:33 volumio sudo[31643]: pam_unix(sudo:session): session closed for user root Jan 28 10:03:33 volumio sudo[31645]: pam_unix(sudo:session): session closed for user root Jan 28 10:03:33 volumio volumio[31367]: info: CoreCommandRouter::volumioGetState Jan 28 10:03:33 volumio volumio[31367]: info: CorePlayQueue::getTrack 0 Jan 28 10:03:33 volumio volumio[31367]: info: Shairport-Sync Started Jan 28 10:03:33 volumio volumio[31367]: Error adding Membership: Error: addMembership EINVAL Jan 28 10:03:33 volumio volumio[31367]: info: Shairport-Sync Started Jan 28 10:03:33 volumio volumio[31367]: info: Shairport-Sync Started Jan 28 10:03:33 volumio volumio[31367]: 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 28 10:03:33 volumio volumio[31367]: info: Spotify Successfully logged in Jan 28 10:03:33 volumio volumio[31367]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 10:03:33 volumio volumio[31367]: info: [1769569413812] CoreMusicLibrary::Adding element Spotify Jan 28 10:03:33 volumio volumio[31367]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 10:03:33 volumio volumio[31367]: Cannot find translation for source YouTube Music Jan 28 10:03:33 volumio volumio[31367]: Cannot find translation for source Spotify Jan 28 10:03:34 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 10:03:34 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 10:03:34 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 10:03:34 volumio volumio[31367]: info: [yt-cast-receiver] DIAL server listening on port 8098 Jan 28 10:03:34 volumio volumio[31367]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 10:03:34 volumio volumio[31367]: info: VolumeController:: Volume=100 Mute =false Jan 28 10:03:34 volumio volumio[31367]: info: CoreCommandRouter::volumioGetState Jan 28 10:03:34 volumio volumio[31367]: info: CorePlayQueue::getTrack 0 Jan 28 10:03:34 volumio volumio[31367]: info: CoreStateMachine::pushState Jan 28 10:03:34 volumio volumio[31367]: info: CorePlayQueue::getTrack 0 Jan 28 10:03:34 volumio volumio[31367]: info: CoreCommandRouter::volumioPushState Jan 28 10:03:35 volumio volumio[31367]: info: go-librespot daemon successfully initialized Jan 28 10:03:36 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 9. Jan 28 10:03:36 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 10:03:36 volumio mpd[31592]: 2026-01-28T10:03:36 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 28 10:03:36 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 10:03:36 volumio go-librespot[31683]: go-librespot daemon starting... Jan 28 10:03:36 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 28 10:03:36 volumio sudo[31544]: pam_unix(sudo:session): session closed for user root Jan 28 10:03:36 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 10:03:36 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 10:03:36 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 10:03:36 volumio sudo[31556]: pam_unix(sudo:session): session closed for user root Jan 28 10:03:36 volumio go-librespot[31686]: time="2026-01-28T10:03:36+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 10:03:36 volumio go-librespot[31686]: time="2026-01-28T10:03:36+07:00" level=debug msg="app state loaded" Jan 28 10:03:36 volumio go-librespot[31686]: time="2026-01-28T10:03:36+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 10:03:36 volumio volumio[31367]: error: MPD error: The expression evaluated to a falsy value: Jan 28 10:03:36 volumio volumio[31367]: assert.ok(self.idling) Jan 28 10:03:36 volumio volumio[31367]: error: The expression evaluated to a falsy value: Jan 28 10:03:36 volumio volumio[31367]: assert.ok(self.idling) Jan 28 10:03:36 volumio volumio[31367]: info: Completed starting Core Plugins Jan 28 10:03:36 volumio volumio[31367]: info: ------------------------------------------- Jan 28 10:03:36 volumio volumio[31367]: info: ----- MyVolumio plugins startup ---- Jan 28 10:03:36 volumio volumio[31367]: info: ------------------------------------------- Jan 28 10:03:36 volumio volumio[31367]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 28 10:03:36 volumio volumio[31367]: info: MPD running with PID31592 Jan 28 10:03:36 volumio volumio[31367]: ,establishing connection Jan 28 10:03:36 volumio volumio[31367]: error: updateQueue error: null Jan 28 10:03:36 volumio volumio[31367]: error: updateQueue error: null Jan 28 10:03:36 volumio go-librespot[31686]: time="2026-01-28T10:03:36+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 28 10:03:36 volumio go-librespot[31686]: time="2026-01-28T10:03:36+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 28 10:03:36 volumio go-librespot[31686]: time="2026-01-28T10:03:36+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 28 10:03:36 volumio go-librespot[31686]: time="2026-01-28T10:03:36+07:00" level=info msg="zeroconf server listening on port 38385" Jan 28 10:03:37 volumio go-librespot[31686]: time="2026-01-28T10:03:37+07:00" level=debug msg="obtained new client token: AABHKvMrWfuEh2IMHoTsERvfHkse1MABkUstXP2q4UK09vl51zFWR/wZDfdWiJVaC8NS0SaCtKRHhjfjERRH2d70Vc5Ios6ObXuVfNdQNfycOVJAm/XKw38n/1OLEQpHIX7JhwNEa+1WE7x10y5fZC4P0OaycY7Utd/kd4GvnYlzYR3qCitgovx2nVLvRSkPL9Fdw0sPRz0Mw+wlZXOHnyzsmDM5kNDp4zAncqj8/EAY1QlQ5l5MA5RM" Jan 28 10:03:37 volumio go-librespot[31686]: time="2026-01-28T10:03:37+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 10:03:37 volumio go-librespot[31686]: time="2026-01-28T10:03:37+07:00" level=debug msg="completed keyexchange" Jan 28 10:03:37 volumio go-librespot[31686]: time="2026-01-28T10:03:37+07:00" level=debug msg="completed challenge" Jan 28 10:03:37 volumio go-librespot[31686]: time="2026-01-28T10:03:37+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 28 10:03:37 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 10:03:37 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 10:03:38 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 10:03:38 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 10:03:38 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 10:03:38 volumio volumio[31367]: info: Initializing connection to go-librespot Websocket Jan 28 10:03:38 volumio volumio[31367]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 10:03:40 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 10:03:40 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 10:03:40 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 10:03:40 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 10. Jan 28 10:03:40 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 10:03:40 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 10:03:40 volumio go-librespot[31695]: go-librespot daemon starting... Jan 28 10:03:40 volumio go-librespot[31696]: time="2026-01-28T10:03:40+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 10:03:40 volumio go-librespot[31696]: time="2026-01-28T10:03:40+07:00" level=debug msg="app state loaded" Jan 28 10:03:40 volumio go-librespot[31696]: time="2026-01-28T10:03:40+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 10:03:41 volumio go-librespot[31696]: time="2026-01-28T10:03:41+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 10:03:41 volumio go-librespot[31696]: time="2026-01-28T10:03:41+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 28 10:03:41 volumio go-librespot[31696]: time="2026-01-28T10:03:41+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 28 10:03:41 volumio go-librespot[31696]: time="2026-01-28T10:03:41+07:00" level=info msg="zeroconf server listening on port 37615" Jan 28 10:03:41 volumio volumio[31367]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 28 10:03:41 volumio go-librespot[31696]: time="2026-01-28T10:03:41+07:00" level=debug msg="obtained new client token: AABX0Ait0zI9Tq3zomR1gUAKlvUsOkHviAQvIVHgCrAFVCYo7qcz8K4HAeheMhDqCkiQdpqFhaAsS6mrp5XjtTeMgmafqu/vuliJIeNsZ2AmYhJf4e5fqCC3mEuKOvQCj4sgoegyWKE1Cr3ej8BmcIVroFI/dn1cjOtrjy/Nik86gluGFuYIUGgn1dECzCpnbdrRZD0tO52cbiV5xBXmU7amquKHh45LsSEAjR115yC2O2jRw+O9MR3DZ3s=" Jan 28 10:03:41 volumio go-librespot[31696]: time="2026-01-28T10:03:41+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 10:03:41 volumio go-librespot[31696]: time="2026-01-28T10:03:41+07:00" level=debug msg="completed keyexchange" Jan 28 10:03:41 volumio go-librespot[31696]: time="2026-01-28T10:03:41+07:00" level=debug msg="completed challenge" Jan 28 10:03:41 volumio go-librespot[31696]: time="2026-01-28T10:03:41+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 28 10:03:41 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 10:03:41 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 10:03:41 volumio volumio[31367]: info: Initializing connection to go-librespot Websocket Jan 28 10:03:41 volumio volumio[31367]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 10:03:42 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 10:03:42 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 10:03:42 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 10:03:44 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 10:03:44 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 10:03:44 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 10:03:44 volumio volumio[31367]: info: Initializing connection to go-librespot Websocket Jan 28 10:03:44 volumio volumio[31367]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 10:03:44 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 11. Jan 28 10:03:44 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 10:03:45 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 10:03:45 volumio go-librespot[31703]: go-librespot daemon starting... Jan 28 10:03:45 volumio go-librespot[31704]: time="2026-01-28T10:03:45+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 10:03:45 volumio go-librespot[31704]: time="2026-01-28T10:03:45+07:00" level=debug msg="app state loaded" Jan 28 10:03:45 volumio go-librespot[31704]: time="2026-01-28T10:03:45+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 10:03:45 volumio go-librespot[31704]: time="2026-01-28T10:03:45+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 28 10:03:45 volumio go-librespot[31704]: time="2026-01-28T10:03:45+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 28 10:03:45 volumio go-librespot[31704]: time="2026-01-28T10:03:45+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 28 10:03:45 volumio go-librespot[31704]: time="2026-01-28T10:03:45+07:00" level=info msg="zeroconf server listening on port 46423" Jan 28 10:03:45 volumio volumio[31367]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 28 10:03:45 volumio volumio[31367]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 28 10:03:45 volumio volumio[31367]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 28 10:03:45 volumio volumio[31367]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jan 28 10:03:45 volumio volumio[31367]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 28 10:03:45 volumio volumio[31367]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 28 10:03:45 volumio volumio[31367]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 28 10:03:45 volumio volumio[31367]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 28 10:03:45 volumio volumio[31367]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 28 10:03:45 volumio volumio[31367]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 28 10:03:45 volumio volumio[31367]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jan 28 10:03:45 volumio volumio[31367]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 28 10:03:45 volumio volumio[31367]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 28 10:03:45 volumio volumio[31367]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 28 10:03:45 volumio volumio[31367]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jan 28 10:03:45 volumio volumio[31367]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 28 10:03:45 volumio volumio[31367]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 28 10:03:45 volumio volumio[31367]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 28 10:03:45 volumio volumio[31367]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 28 10:03:45 volumio volumio[31367]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 28 10:03:45 volumio volumio[31367]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 28 10:03:45 volumio volumio[31367]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jan 28 10:03:45 volumio volumio[31367]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 28 10:03:45 volumio volumio[31367]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jan 28 10:03:45 volumio volumio[31367]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 28 10:03:45 volumio volumio[31367]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 28 10:03:45 volumio volumio[31367]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 28 10:03:45 volumio volumio[31367]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 28 10:03:45 volumio volumio[31367]: info: Adding plugin bluetooth to MyMusic Plugins Jan 28 10:03:45 volumio volumio[31367]: info: Adding plugin multiroom to MyMusic Plugins Jan 28 10:03:45 volumio volumio[31367]: info: Adding plugin metavolumio to MyMusic Plugins Jan 28 10:03:45 volumio volumio[31367]: info: Adding plugin cd_controller to MyMusic Plugins Jan 28 10:03:45 volumio volumio[31367]: info: Adding plugin qobuzconnect to MyMusic Plugins Jan 28 10:03:45 volumio volumio[31367]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 28 10:03:45 volumio volumio[31367]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 28 10:03:45 volumio volumio[31367]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 28 10:03:45 volumio go-librespot[31704]: time="2026-01-28T10:03:45+07:00" level=debug msg="obtained new client token: AABKksooumSM5kmcg00kqf24c7sWHDzCiNsHQyOJIkjK2YAxd8s7FlmdIAj4ZV0mlOmOqpnhPwTiG3aekPD5JBO7e4L6wOSGm5tlV0D+aeuaqIGGV/lkoXqSswnm6a7gChdr0+8sxw4iOWO/ls60Y5vWOD3pv2TCZDECm/MP80kDTxeyshh+K25NqlabxGZK3LTSreSCo1e4rPLl8x1nJzgQBcyqAcG2mjqTvgmvX+zkftWd20BjFSrI1C4=" Jan 28 10:03:45 volumio go-librespot[31704]: time="2026-01-28T10:03:45+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 10:03:46 volumio go-librespot[31704]: time="2026-01-28T10:03:46+07:00" level=debug msg="completed keyexchange" Jan 28 10:03:46 volumio go-librespot[31704]: time="2026-01-28T10:03:46+07:00" level=debug msg="completed challenge" Jan 28 10:03:46 volumio go-librespot[31704]: time="2026-01-28T10:03:46+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 10:03:46 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 10:03:46 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 10:03:46 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 10:03:46 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 10:03:46 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 10:03:47 volumio volumio[31367]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 28 10:03:47 volumio volumio[31367]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 28 10:03:47 volumio volumio[31367]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 10:03:47 volumio volumio[31367]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 10:03:47 volumio volumio[31367]: info: Starting MyVolumio Remote Streaming Endpoints Jan 28 10:03:47 volumio volumio[31367]: info: MyVolumio login type: Token Jan 28 10:03:47 volumio volumio[31367]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 28 10:03:47 volumio volumio[31367]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 28 10:03:48 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 10:03:48 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 10:03:48 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 10:03:49 volumio volumio[31367]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 28 10:03:49 volumio volumio[31367]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 28 10:03:49 volumio volumio[31367]: info: Streaming services startup Jan 28 10:03:49 volumio volumio[31367]: info: Starting Streaming Daemon Jan 28 10:03:49 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 12. Jan 28 10:03:49 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 10:03:49 volumio sudo[31728]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 28 10:03:49 volumio sudo[31728]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 10:03:49 volumio volumio[31367]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 28 10:03:49 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 10:03:49 volumio go-librespot[31727]: go-librespot daemon starting... Jan 28 10:03:49 volumio go-librespot[31734]: time="2026-01-28T10:03:49+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 10:03:49 volumio go-librespot[31734]: time="2026-01-28T10:03:49+07:00" level=debug msg="app state loaded" Jan 28 10:03:49 volumio sudo[31728]: pam_unix(sudo:session): session closed for user root Jan 28 10:03:49 volumio go-librespot[31734]: time="2026-01-28T10:03:49+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 10:03:49 volumio volumio[31367]: info: Initializing connection to go-librespot Websocket Jan 28 10:03:49 volumio volumio[31367]: error: Cannot start Volumio Streaming Daemon Jan 28 10:03:49 volumio volumio[31367]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 28 10:03:49 volumio volumio[31367]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 28 10:03:49 volumio go-librespot[31734]: time="2026-01-28T10:03:49+07:00" level=debug msg="new websocket client" Jan 28 10:03:49 volumio volumio[31367]: info: Connection to go-librespot Websocket established Jan 28 10:03:49 volumio go-librespot[31734]: time="2026-01-28T10:03:49+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 28 10:03:49 volumio go-librespot[31734]: time="2026-01-28T10:03:49+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 28 10:03:49 volumio go-librespot[31734]: time="2026-01-28T10:03:49+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 28 10:03:49 volumio go-librespot[31734]: time="2026-01-28T10:03:49+07:00" level=info msg="zeroconf server listening on port 38609" Jan 28 10:03:50 volumio go-librespot[31734]: time="2026-01-28T10:03:50+07:00" level=debug msg="obtained new client token: AADKvzGAWLMDnwaAzuGNGiq694Bycyd2NFS9fWfpSku88qa4+NlNq9ii/24txfXhYMWvqPTRknaHkoGGBj/GORaFG+VJycqwPg5RDw7mVlHIWU1M/kSH+lmBrvBZWt7AXzOHCzLOFpK/NmaDxxpLIXaAo3EfOiChB1GZABtYDAbeXpsT72cUEM67BfvpZ1L8/QBRVyD3V85pQaourmKi9AFtmID9agMxCTEaoJVJhMxkHBUw7uQ3kmEQ" Jan 28 10:03:50 volumio go-librespot[31734]: time="2026-01-28T10:03:50+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 10:03:50 volumio go-librespot[31734]: time="2026-01-28T10:03:50+07:00" level=debug msg="completed keyexchange" Jan 28 10:03:50 volumio go-librespot[31734]: time="2026-01-28T10:03:50+07:00" level=debug msg="completed challenge" Jan 28 10:03:50 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 10:03:50 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 10:03:50 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 10:03:50 volumio volumio[31367]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Jan 28 10:03:50 volumio go-librespot[31734]: time="2026-01-28T10:03:50+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 28 10:03:50 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 10:03:50 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 10:03:50 volumio volumio[31367]: info: Connection to go-librespot Websocket closed Jan 28 10:03:51 volumio volumio[31367]: info: MyVolumio token set successfully Jan 28 10:03:51 volumio volumio[31367]: info: MYVOLUMIO: Adding device Jan 28 10:03:51 volumio volumio[31367]: info: MYVOLUMIO: Evaluating Server Jan 28 10:03:51 volumio volumio[31367]: info: MyVolumio status changed Jan 28 10:03:51 volumio volumio[31367]: info: Streaming services startup Jan 28 10:03:51 volumio volumio[31367]: info: Starting Streaming Daemon Jan 28 10:03:51 volumio volumio[31367]: info: Removing browser output: myVolumio user plan is not superstar Jan 28 10:03:51 volumio volumio[31367]: info: Removing audio output: Jan 28 10:03:51 volumio volumio[31367]: info: Stoppping Tunnel 1 Jan 28 10:03:51 volumio sudo[31764]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 28 10:03:51 volumio sudo[31764]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 10:03:51 volumio sudo[31767]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Jan 28 10:03:51 volumio sudo[31767]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 10:03:51 volumio sudo[31764]: pam_unix(sudo:session): session closed for user root Jan 28 10:03:51 volumio volumio[31367]: error: Cannot start Volumio Streaming Daemon Jan 28 10:03:51 volumio volumio[31367]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 28 10:03:51 volumio volumio[31367]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 28 10:03:51 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 28 10:03:51 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 28 10:03:51 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 28 10:03:51 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 28 10:03:51 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 28 10:03:51 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 28 10:03:51 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 28 10:03:51 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 28 10:03:51 volumio sudo[31767]: pam_unix(sudo:session): session closed for user root Jan 28 10:03:51 volumio volumio[31367]: info: Setting Geolocation for MyVolumio to as1 Jan 28 10:03:51 volumio volumio[31367]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 10:03:51 volumio volumio[31367]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 10:03:51 volumio volumio[31367]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 10:03:51 volumio volumio[31367]: info: Remote SSH Stopped Jan 28 10:03:52 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 10:03:52 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 10:03:52 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 10:03:52 volumio volumio[31367]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Jan 28 10:03:52 volumio volumio[31367]: info: Getting Spotify volume Jan 28 10:03:52 volumio volumio[31367]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 10:03:52 volumio volumio[31367]: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 10:03:52 volumio volumio[31367]: at TCPConnectWrap.afterConnect [as oncomplete] (node:net:1595:16) { Jan 28 10:03:52 volumio volumio[31367]: errno: -111, Jan 28 10:03:52 volumio volumio[31367]: code: 'ECONNREFUSED', Jan 28 10:03:52 volumio volumio[31367]: syscall: 'connect', Jan 28 10:03:52 volumio volumio[31367]: address: '127.0.0.1', Jan 28 10:03:52 volumio volumio[31367]: port: 9879, Jan 28 10:03:52 volumio volumio[31367]: response: undefined Jan 28 10:03:52 volumio volumio[31367]: } Jan 28 10:03:52 volumio volumio[31367]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 10:03:53 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 13. Jan 28 10:03:53 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 10:03:53 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 10:03:53 volumio go-librespot[31781]: go-librespot daemon starting... Jan 28 10:03:53 volumio go-librespot[31782]: time="2026-01-28T10:03:53+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 10:03:53 volumio go-librespot[31782]: time="2026-01-28T10:03:53+07:00" level=debug msg="app state loaded" Jan 28 10:03:53 volumio go-librespot[31782]: time="2026-01-28T10:03:53+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 10:03:54 volumio sudo[31792]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-28 10:02' Jan 28 10:03:54 volumio sudo[31792]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 10:03:54 volumio go-librespot[31782]: time="2026-01-28T10:03:54+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 28 10:03:54 volumio go-librespot[31782]: time="2026-01-28T10:03:54+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 28 10:03:54 volumio go-librespot[31782]: time="2026-01-28T10:03:54+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 28 10:03:54 volumio go-librespot[31782]: time="2026-01-28T10:03:54+07:00" level=info msg="zeroconf server listening on port 43035" Jan 28 10:03:54 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 10:03:54 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 10:03:54 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 10:03:54 volumio go-librespot[31782]: time="2026-01-28T10:03:54+07:00" level=debug msg="obtained new client token: AADyx5mbUUAhtWp5Y15Poz8QJp8qLScIHPDSxHjYDO2NZkw/gq3kIjlCUdu42WY9JGwRWxW5UPSOu0jh9zNAK+n/4mYr8z3KKTcZnCKUSy90dBYU+jIaG/8oqp5/6aiWROfHEyRSQGYqMEXIT7jMc1lw8gZSoTo/Ps7yW5/ZEkjR1ZTJ6sGSLZoVSzciTai88XyJBeTvnRum6pMWKWeE+eb6HTK4BbxltmPFjIy/FylQezivbSZJ/O3sCzc=" Jan 28 10:03:54 volumio sudo[31792]: pam_unix(sudo:session): session closed for user root Jan 28 10:03:54 volumio go-librespot[31782]: time="2026-01-28T10:03:54+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 10:03:54 volumio go-librespot[31782]: time="2026-01-28T10:03:54+07:00" level=debug msg="completed keyexchange" Jan 28 10:03:54 volumio go-librespot[31782]: time="2026-01-28T10:03:54+07:00" level=debug msg="completed challenge" Jan 28 10:03:54 volumio volumio-remote-updater[628]: [2026-01-28 10:03:54] [error] handle_read_frame error: websocketpp.transport:7 (End of File) Jan 28 10:03:54 volumio volumio-remote-updater[628]: [2026-01-28 10:03:54] [disconnect] Disconnect close local:[1006,End of File] remote:[1006] Jan 28 10:03:54 volumio systemd[1]: volumio.service: Main process exited, code=exited, status=1/FAILURE Jan 28 10:03:54 volumio systemd[1]: volumio.service: Failed with result 'exit-code'. Jan 28 10:03:54 volumio systemd[1]: volumio.service: Consumed 1min 483ms CPU time. Jan 28 10:03:54 volumio go-librespot[31782]: time="2026-01-28T10:03:54+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 28 10:03:54 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 28 10:03:54 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 10:03:54 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 10:03:54 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 28 10:03:54 volumio systemd[1]: volumio.service: Scheduled restart job, restart counter is at 9956. Jan 28 10:03:54 volumio systemd[1]: Started dynamicswap.service - dynamicswap service. Jan 28 10:03:54 volumio systemd[1]: Stopped volumio.service - Volumio Backend Module. Jan 28 10:03:54 volumio systemd[1]: volumio.service: Consumed 1min 483ms CPU time. Jan 28 10:03:54 volumio systemd[1]: Started volumio.service - Volumio Backend Module. Jan 28 10:03:54 volumio systemd[1]: dynamicswap.service: Deactivated successfully. Jan 28 10:03:56 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 10:03:56 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 10:03:56 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 10:03:57 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 14. Jan 28 10:03:57 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 10:03:57 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 10:03:57 volumio go-librespot[31820]: go-librespot daemon starting... Jan 28 10:03:57 volumio go-librespot[31821]: time="2026-01-28T10:03:57+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 10:03:57 volumio go-librespot[31821]: time="2026-01-28T10:03:57+07:00" level=debug msg="app state loaded" Jan 28 10:03:57 volumio go-librespot[31821]: time="2026-01-28T10:03:57+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 10:03:58 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 10:03:58 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 10:03:58 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 10:03:58 volumio go-librespot[31821]: time="2026-01-28T10:03:58+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 28 10:03:58 volumio go-librespot[31821]: time="2026-01-28T10:03:58+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 28 10:03:58 volumio go-librespot[31821]: time="2026-01-28T10:03:58+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 28 10:03:58 volumio volumio[31804]: info: ------------------------------------------- Jan 28 10:03:58 volumio volumio[31804]: info: ----- Volumio3 ---- Jan 28 10:03:58 volumio volumio[31804]: info: ------------------------------------------- Jan 28 10:03:58 volumio volumio[31804]: info: ----- System startup ---- Jan 28 10:03:58 volumio volumio[31804]: info: ------------------------------------------- Jan 28 10:03:58 volumio go-librespot[31821]: time="2026-01-28T10:03:58+07:00" level=info msg="zeroconf server listening on port 41793" Jan 28 10:03:58 volumio go-librespot[31821]: time="2026-01-28T10:03:58+07:00" level=debug msg="obtained new client token: AABBI44T5uZM00EGr5pORfbapeJAt68ZY4RuCH4/3GYYdSb5O+STvFNc9k2uLhly+orXq/kdTjx6YpCUkvJOhoIGOAegKQbS+XXKwJkL9DKiP6ad4qAKEX3q2CpBr3e05w4kC1RNVoxbpeHXCCoADHg1idlP9fZeRB8vIP3MJ2zITw8yh74A3QZURJzXEK4fZIQ5j3SHQUykeIryHXd4mX5S9+HcFoEA0IhqbtwfsRMD++O1crsWzjsMntI=" Jan 28 10:03:58 volumio go-librespot[31821]: time="2026-01-28T10:03:58+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 10:03:58 volumio go-librespot[31821]: time="2026-01-28T10:03:58+07:00" level=debug msg="completed keyexchange" Jan 28 10:03:58 volumio go-librespot[31821]: time="2026-01-28T10:03:58+07:00" level=debug msg="completed challenge" Jan 28 10:03:59 volumio go-librespot[31821]: time="2026-01-28T10:03:59+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 28 10:03:59 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 10:03:59 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 10:03:59 volumio volumio-remote-updater[628]: [2026-01-28 10:03:59] [connect] Successful connection Jan 28 10:03:59 volumio volumio[31804]: info: MYVOLUMIO Environment detected Jan 28 10:03:59 volumio volumio[31804]: info: Plugin folders cleanup Jan 28 10:03:59 volumio volumio[31804]: info: Scanning into folder /volumio/app/plugins/ Jan 28 10:03:59 volumio volumio[31804]: info: Scanning category audio_interface Jan 28 10:03:59 volumio volumio[31804]: info: Scanning category miscellanea Jan 28 10:03:59 volumio volumio[31804]: info: Scanning category music_service Jan 28 10:03:59 volumio volumio[31804]: info: Scanning category plugins.json Jan 28 10:03:59 volumio volumio[31804]: info: Scanning category system_controller Jan 28 10:03:59 volumio volumio[31804]: info: Scanning category user_interface Jan 28 10:03:59 volumio volumio[31804]: info: Scanning into folder /data/plugins/ Jan 28 10:03:59 volumio volumio[31804]: info: Scanning category music_service Jan 28 10:03:59 volumio volumio[31804]: info: Plugin folders cleanup completed Jan 28 10:03:59 volumio volumio[31804]: info: ------------------------------------------- Jan 28 10:03:59 volumio volumio[31804]: info: ----- Core plugins startup ---- Jan 28 10:03:59 volumio volumio[31804]: info: ------------------------------------------- Jan 28 10:03:59 volumio volumio[31804]: info: Loading plugins from folder /volumio/app/plugins/ Jan 28 10:03:59 volumio volumio[31804]: info: Adding plugin upnp to MyMusic Plugins Jan 28 10:03:59 volumio volumio[31804]: info: Adding plugin airplay_emulation to MyMusic Plugins Jan 28 10:03:59 volumio volumio[31804]: info: Adding plugin upnp_browser to MyMusic Plugins Jan 28 10:03:59 volumio volumio[31804]: info: Loading plugins from folder /data/plugins/ Jan 28 10:04:00 volumio volumio[31804]: info: Loading plugin "system"... Jan 28 10:04:00 volumio volumio[31804]: info: Loading plugin "appearance"... Jan 28 10:04:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 10:04:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 10:04:00 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 10:04:01 volumio volumio[31804]: info: Loading plugin "network"... Jan 28 10:04:01 volumio volumio[31804]: info: Refreshing Cached IP Addresses Jan 28 10:04:01 volumio sudo[31842]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 28 10:04:02 volumio sudo[31842]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 10:04:02 volumio sudo[31844]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 28 10:04:02 volumio sudo[31844]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 10:04:02 volumio volumio[31804]: info: Loading plugin "services"... Jan 28 10:04:02 volumio volumio[31804]: info: Loading plugin "alsa_controller"... Jan 28 10:04:02 volumio sudo[31842]: pam_unix(sudo:session): session closed for user root Jan 28 10:04:02 volumio sudo[31844]: pam_unix(sudo:session): session closed for user root Jan 28 10:04:02 volumio sudo[31851]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan Jan 28 10:04:02 volumio sudo[31851]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 10:04:02 volumio volumio[31804]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 10:04:02 volumio volumio[31804]: info: Loading plugin "wizard"... Jan 28 10:04:02 volumio volumio[31804]: info: Loading plugin "networkfs"... Jan 28 10:04:02 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 15. Jan 28 10:04:02 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 10:04:02 volumio volumio[31804]: info: Starting Udev Watcher for removable devices Jan 28 10:04:02 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 10:04:02 volumio go-librespot[31875]: go-librespot daemon starting... Jan 28 10:04:02 volumio volumio[31804]: info: Ignoring mount for partition: boot Jan 28 10:04:02 volumio volumio[31804]: info: Ignoring mount for partition: volumio Jan 28 10:04:02 volumio volumio[31804]: info: Ignoring mount for partition: volumio_data Jan 28 10:04:02 volumio volumio[31804]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 10:04:02 volumio volumio[31804]: info: Loading plugin "volumio_command_line_client"... Jan 28 10:04:02 volumio volumio[31804]: info: Loading plugin "upnp"... Jan 28 10:04:02 volumio volumio[31804]: info: [1769569442346] Starting Upmpd Daemon Jan 28 10:04:02 volumio volumio[31804]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 10:04:02 volumio volumio[31804]: info: Loading plugin "my_music"... Jan 28 10:04:02 volumio go-librespot[31876]: time="2026-01-28T10:04:02+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 10:04:02 volumio go-librespot[31876]: time="2026-01-28T10:04:02+07:00" level=debug msg="app state loaded" Jan 28 10:04:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 10:04:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 10:04:02 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 10:04:02 volumio go-librespot[31876]: time="2026-01-28T10:04:02+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 10:04:02 volumio volumio[31804]: info: Loading plugin "mpd"... Jan 28 10:04:02 volumio go-librespot[31876]: time="2026-01-28T10:04:02+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 28 10:04:02 volumio go-librespot[31876]: time="2026-01-28T10:04:02+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 28 10:04:02 volumio go-librespot[31876]: time="2026-01-28T10:04:02+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 28 10:04:02 volumio go-librespot[31876]: time="2026-01-28T10:04:02+07:00" level=info msg="zeroconf server listening on port 46671" Jan 28 10:04:03 volumio volumio[31804]: info: Loading plugin "upnp_browser"... Jan 28 10:04:03 volumio go-librespot[31876]: time="2026-01-28T10:04:03+07:00" level=debug msg="obtained new client token: AAACvQNQGWzRYvVWadv2+n6Il8dFT4wxgEdf+xg8HECdKnZTUw1YvVP0IjIHAiN3vpkd0t0s3Ou+0Bvuw3w5mdNdt+9Dl4UORQ+E+l/D9z2tPjLmQfckCJI3dm9uTNNoXc6Hs8Cv6PnO7IrJVuKz4b5P7TfRk+pi3AaokFlOgY1gLdAjF6vyWB4ZpZJPuyVU8L9JnqgYLNm5xbYO05s6O6pTtfs2uYm9LYmftlu01sp/2QtjLyxOme15" Jan 28 10:04:03 volumio go-librespot[31876]: time="2026-01-28T10:04:03+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 10:04:03 volumio go-librespot[31876]: time="2026-01-28T10:04:03+07:00" level=debug msg="completed keyexchange" Jan 28 10:04:03 volumio go-librespot[31876]: time="2026-01-28T10:04:03+07:00" level=debug msg="completed challenge" Jan 28 10:04:03 volumio go-librespot[31876]: time="2026-01-28T10:04: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 28 10:04:03 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 10:04:03 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 10:04:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 10:04:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 10:04:04 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 10:04:04 volumio sudo[31851]: pam_unix(sudo:session): session closed for user root Jan 28 10:04:05 volumio volumio[31804]: info: Starting UPNP Browser Jan 28 10:04:05 volumio volumio[31804]: info: Loading plugin "alarm-clock"... Jan 28 10:04:06 volumio volumio[31804]: info: Loading plugin "airplay_emulation"... Jan 28 10:04:06 volumio volumio[31804]: info: Starting Shairport Sync Jan 28 10:04:06 volumio volumio[31804]: info: Loading plugin "last_100"... Jan 28 10:04:06 volumio volumio[31804]: info: Loading plugin "webradio"... Jan 28 10:04:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 10:04:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 10:04:06 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 10:04:06 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 16. Jan 28 10:04:06 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 10:04:06 volumio volumio[31804]: info: Loading plugin "i2s_dacs"... Jan 28 10:04:06 volumio volumio[31804]: info: Loading plugin "volumiodiscovery"... Jan 28 10:04:06 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 10:04:06 volumio go-librespot[31883]: go-librespot daemon starting... Jan 28 10:04:06 volumio volumio[31804]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 28 10:04:06 volumio volumio[31804]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 10:04:06 volumio volumio[31804]: *** WARNING *** For more information see Jan 28 10:04:06 volumio volumio[31804]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 28 10:04:06 volumio volumio[31804]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 10:04:06 volumio volumio[31804]: *** WARNING *** For more information see Jan 28 10:04:06 volumio node[31804]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi. Jan 28 10:04:06 volumio node[31804]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 10:04:06 volumio node[31804]: *** WARNING *** For more information see Jan 28 10:04:06 volumio node[31804]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. Jan 28 10:04:06 volumio node[31804]: *** WARNING *** Please fix your application to use the native API of Avahi! Jan 28 10:04:06 volumio node[31804]: *** WARNING *** For more information see Jan 28 10:04:06 volumio volumio[31804]: info: Applying required configuration parameters for plugin volumiodiscovery Jan 28 10:04:06 volumio volumio[31804]: info: Discovery: Started advertising with name: Volumio Jan 28 10:04:06 volumio go-librespot[31884]: time="2026-01-28T10:04:06+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 10:04:06 volumio go-librespot[31884]: time="2026-01-28T10:04:06+07:00" level=debug msg="app state loaded" Jan 28 10:04:06 volumio go-librespot[31884]: time="2026-01-28T10:04:06+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 10:04:06 volumio volumio[31804]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Jan 28 10:04:06 volumio volumio[31804]: info: Loading plugin "spop"... Jan 28 10:04:07 volumio go-librespot[31884]: time="2026-01-28T10:04: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-gew4.spotify.com:80]" Jan 28 10:04:07 volumio go-librespot[31884]: time="2026-01-28T10:04:07+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 28 10:04:07 volumio go-librespot[31884]: time="2026-01-28T10:04:07+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 28 10:04:07 volumio go-librespot[31884]: time="2026-01-28T10:04:07+07:00" level=info msg="zeroconf server listening on port 39155" Jan 28 10:04:07 volumio go-librespot[31884]: time="2026-01-28T10:04:07+07:00" level=debug msg="obtained new client token: AAAqcIPy5JrfDGINQVbO8CO4jNMrdQPPywaPZg6qyifgYKeYtMWTNRmB6aHIuVjuJPR3H7OLvDBtGvTr2w6gbq7rPLka1ZyRtokdzV/+RnPOVcZvFi6veidj59si7A80kYNShDJABjKBR0xbK7BHlG1BPPHRZ9aRT3CYaJN6my4k67R9b63KJ9Xe3E1f4vcaVZP00fi7/hnFuIaj0hpDv26BUCvY/X/a2TMhAtTiFU74t/TC1wCnljOOnOo=" Jan 28 10:04:07 volumio go-librespot[31884]: time="2026-01-28T10:04:07+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 10:04:07 volumio go-librespot[31884]: time="2026-01-28T10:04:07+07:00" level=debug msg="completed keyexchange" Jan 28 10:04:07 volumio go-librespot[31884]: time="2026-01-28T10:04:07+07:00" level=debug msg="completed challenge" Jan 28 10:04:07 volumio go-librespot[31884]: time="2026-01-28T10:04:07+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 28 10:04:07 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 10:04:07 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 10:04:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 10:04:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 10:04:08 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 10:04:08 volumio volumio[31804]: info: Loading plugin "ytcr"... Jan 28 10:04:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 10:04:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 10:04:10 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 10:04:10 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 17. Jan 28 10:04:10 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 10:04:11 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 10:04:11 volumio go-librespot[31895]: go-librespot daemon starting... Jan 28 10:04:11 volumio go-librespot[31896]: time="2026-01-28T10:04:11+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 10:04:11 volumio go-librespot[31896]: time="2026-01-28T10:04:11+07:00" level=debug msg="app state loaded" Jan 28 10:04:11 volumio go-librespot[31896]: time="2026-01-28T10:04:11+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 10:04:11 volumio volumio[31804]: info: Loading plugin "ytmusic"... Jan 28 10:04:11 volumio go-librespot[31896]: time="2026-01-28T10:04:11+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gue1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 10:04:11 volumio go-librespot[31896]: time="2026-01-28T10:04:11+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 28 10:04:11 volumio go-librespot[31896]: time="2026-01-28T10:04:11+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 28 10:04:11 volumio go-librespot[31896]: time="2026-01-28T10:04:11+07:00" level=info msg="zeroconf server listening on port 39405" Jan 28 10:04:11 volumio go-librespot[31896]: time="2026-01-28T10:04:11+07:00" level=debug msg="obtained new client token: AAB0nM7Kn/YWBc+nCgkrKD2iJXdOqGq2YDC2ejXzRhOXEhuNw49W6Wd3fRea/VbQMpt7Y2LAkZ2UivtitKAy2vywl45r4S4EQzoypTpYkXsfL/ghamxPU0xYqWKFW+OUMTrQ3ij63clul5M3pS3nGoqKFwRE34GCQTuHMseZvIvfdDkEY3sB1OvMUNGjKboQEYdIgoOQoYxsPfimhjgH0XaQXq8NyS34p2FdbJh+DjpbQX9/R1u8c4aLvxQ=" Jan 28 10:04:12 volumio go-librespot[31896]: time="2026-01-28T10:04:12+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 10:04:12 volumio volumio-remote-updater[628]: [2026-01-28 10:04:12] [connect] Successful connection Jan 28 10:04:12 volumio go-librespot[31896]: time="2026-01-28T10:04:12+07:00" level=debug msg="completed keyexchange" Jan 28 10:04:12 volumio go-librespot[31896]: time="2026-01-28T10:04:12+07:00" level=debug msg="completed challenge" Jan 28 10:04:12 volumio go-librespot[31896]: time="2026-01-28T10:04:12+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 10:04:12 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 10:04:12 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 10:04:12 volumio volumio[31804]: info: Loading plugin "outputs"... Jan 28 10:04:12 volumio volumio[31804]: info: Loading plugin "albumart"... Jan 28 10:04:12 volumio volumio[31804]: info: Plugin example_plugin is not enabled Jan 28 10:04:12 volumio volumio[31804]: info: Loading plugin "inputs"... Jan 28 10:04:12 volumio volumio[31804]: info: Loading plugin "updater_comm"... Jan 28 10:04:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 10:04:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 10:04:12 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 10:04:12 volumio volumio[31804]: info: Plugin mpdemulation is not enabled Jan 28 10:04:12 volumio volumio[31804]: info: Loading plugin "rest_api"... Jan 28 10:04:12 volumio volumio[31804]: info: Loading plugin "websocket"... Jan 28 10:04:12 volumio volumio[31804]: info: Starting Socket.io Server version 1.7.4 Jan 28 10:04:12 volumio volumio[31804]: info: Loading plugin "RoonBridge"... Jan 28 10:04:13 volumio volumio[31804]: info: Applying required configuration parameters for plugin RoonBridge Jan 28 10:04:13 volumio volumio[31804]: info: Loading i18n strings for locale en Jan 28 10:04:13 volumio volumio[31804]: Updating browse sources language Jan 28 10:04:13 volumio volumio[31804]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 10:04:13 volumio volumio[31917]: Forking 3 albumart workers Jan 28 10:04:13 volumio volumio[31804]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 10:04:13 volumio volumio[31804]: info: CoreCommandRouter::initPlayerControls Jan 28 10:04:13 volumio volumio[31804]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 10:04:13 volumio volumio[31804]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 10:04:13 volumio volumio[31804]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 10:04:13 volumio volumio[31804]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 10:04:13 volumio volumio[31804]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 10:04:13 volumio volumio[31804]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 10:04:13 volumio volumio[31804]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 10:04:13 volumio volumio[31804]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 10:04:13 volumio volumio[31804]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 10:04:13 volumio volumio[31804]: Express server listening on port 3000 Jan 28 10:04:13 volumio volumio[31804]: [Metrics] WebUI: 16s 110.36ms Jan 28 10:04:13 volumio volumio[31804]: info: CoreStateMachine::resetVolumioState Jan 28 10:04:13 volumio volumio[31804]: info: CoreStateMachine::getcurrentVolume Jan 28 10:04:13 volumio volumio[31804]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 10:04:13 volumio sudo[31961]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Jan 28 10:04:13 volumio sudo[31961]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 10:04:13 volumio sudo[31964]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Jan 28 10:04:13 volumio sudo[31964]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 10:04:13 volumio sudo[31961]: pam_unix(sudo:session): session closed for user root Jan 28 10:04:13 volumio sudo[31964]: pam_unix(sudo:session): session closed for user root Jan 28 10:04:13 volumio volumio[31804]: info: Volumio Network Manager: Network status updated: 1 Jan 28 10:04:14 volumio volumio[31804]: info: VolumeController:: Volume=100 Mute =false Jan 28 10:04:14 volumio volumio[31804]: info: CoreStateMachine::pushState Jan 28 10:04:14 volumio volumio[31804]: info: CorePlayQueue::getTrack 0 Jan 28 10:04:14 volumio volumio[31804]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 10:04:14 volumio volumio[31804]: info: CoreCommandRouter::volumioPushState Jan 28 10:04:14 volumio volumio[31804]: info: CoreStateMachine::updateTrackBlock Jan 28 10:04:14 volumio volumio[31804]: info: CorePlayQueue::getTrackBlock Jan 28 10:04:14 volumio volumio[31804]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 10:04:14 volumio volumio-remote-updater[628]: [2026-01-28 10:04:14] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=3&transport=websocket&t=1769569452 101 Jan 28 10:04:14 volumio volumio[31804]: 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 28 10:04:14 volumio volumio[31804]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 10:04:14 volumio volumio[31804]: info: Reloading queue from file Jan 28 10:04:14 volumio volumio[31804]: info: CoreStateMachine::setRepeat null single undefined Jan 28 10:04:14 volumio volumio[31804]: info: CoreStateMachine::pushState Jan 28 10:04:14 volumio volumio[31804]: info: CorePlayQueue::getTrack 0 Jan 28 10:04:14 volumio volumio[31804]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Jan 28 10:04:14 volumio volumio[31804]: info: CoreCommandRouter::volumioPushState Jan 28 10:04:14 volumio volumio[31804]: info: CoreStateMachine::setRandom null Jan 28 10:04:14 volumio volumio[31804]: info: CoreStateMachine::pushState Jan 28 10:04:14 volumio volumio[31804]: info: CorePlayQueue::getTrack 0 Jan 28 10:04:14 volumio volumio[31804]: info: CoreCommandRouter::volumioPushState Jan 28 10:04:14 volumio volumio[31804]: info: Setting Device type: Raspberry PI Jan 28 10:04:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 10:04:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 10:04:14 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 10:04:14 volumio volumio[31804]: info: Completed loading Core Plugins Jan 28 10:04:14 volumio volumio[31804]: info: Preparing to generate the ALSA configuration file Jan 28 10:04:14 volumio volumio[31804]: info: VolumeController:: Volume=100 Mute =false Jan 28 10:04:14 volumio volumio[31804]: info: CoreStateMachine::pushState Jan 28 10:04:14 volumio volumio[31804]: info: CorePlayQueue::getTrack 0 Jan 28 10:04:14 volumio volumio[31804]: info: CoreCommandRouter::volumioPushState Jan 28 10:04:14 volumio volumio[31804]: info: Asound.conf file unchanged, so no further update is needed Jan 28 10:04:14 volumio volumio[31804]: info: Output device has changed, restarting MPD Jan 28 10:04:14 volumio sudo[31977]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Jan 28 10:04:14 volumio sudo[31977]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 10:04:14 volumio volumio[31804]: info: Output device has changed, restarting Shairport Sync Jan 28 10:04:14 volumio volumio[31804]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 10:04:14 volumio volumio[31804]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 10:04:14 volumio sudo[31979]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 28 10:04:14 volumio sudo[31979]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 10:04:14 volumio sudo[31982]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 28 10:04:14 volumio sudo[31982]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 10:04:14 volumio sudo[31979]: pam_unix(sudo:session): session closed for user root Jan 28 10:04:14 volumio sudo[31977]: pam_unix(sudo:session): session closed for user root Jan 28 10:04:14 volumio volumio[31804]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 10:04:14 volumio volumio[31804]: info: ___________ START PLUGINS ___________ Jan 28 10:04:14 volumio volumio[31804]: info: ControllerMpd::onStart: Initializing MPD Jan 28 10:04:14 volumio volumio[31804]: info: Creating MPD Configuration file Jan 28 10:04:14 volumio systemd[1]: Stopping mpd.service - Music Player Daemon... Jan 28 10:04:15 volumio sudo[31990]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Jan 28 10:04:15 volumio volumio[31804]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Jan 28 10:04:15 volumio volumio[31804]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 10:04:15 volumio volumio[31804]: info: [1769569455050] CoreMusicLibrary::Adding element Media Servers Jan 28 10:04:15 volumio sudo[31990]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 10:04:15 volumio volumio[31804]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 10:04:15 volumio sudo[31990]: pam_unix(sudo:session): session closed for user root Jan 28 10:04:15 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 28 10:04:15 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 28 10:04:15 volumio systemd[1]: mpd.service: Consumed 7.332s CPU time. Jan 28 10:04:15 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 28 10:04:15 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 28 10:04:15 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 28 10:04:15 volumio volumio[31804]: info: UPNP Browser: Client initialized successfully Jan 28 10:04:15 volumio sudo[31992]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Jan 28 10:04:15 volumio sudo[31992]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 10:04:15 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 28 10:04:15 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 28 10:04:15 volumio volumio[31804]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 10:04:15 volumio volumio[31804]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 10:04:15 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 18. Jan 28 10:04:15 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 10:04:15 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 10:04:15 volumio go-librespot[32001]: go-librespot daemon starting... Jan 28 10:04:15 volumio systemd[1]: mpd.service: Deactivated successfully. Jan 28 10:04:15 volumio volumio[31804]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 10:04:15 volumio systemd[1]: Stopped mpd.service - Music Player Daemon. Jan 28 10:04:15 volumio systemd[1]: mpd.socket: Deactivated successfully. Jan 28 10:04:15 volumio systemd[1]: Closed mpd.socket - Music Player Daemon Socket. Jan 28 10:04:15 volumio systemd[1]: Stopping mpd.socket - Music Player Daemon Socket... Jan 28 10:04:15 volumio volumio[31804]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 10:04:15 volumio volumio[31804]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 10:04:15 volumio systemd[1]: Listening on mpd.socket - Music Player Daemon Socket. Jan 28 10:04:15 volumio systemd[1]: Starting mpd.service - Music Player Daemon... Jan 28 10:04:15 volumio go-librespot[32002]: time="2026-01-28T10:04:15+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 10:04:15 volumio go-librespot[32002]: time="2026-01-28T10:04:15+07:00" level=debug msg="app state loaded" Jan 28 10:04:15 volumio go-librespot[32002]: time="2026-01-28T10:04:15+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 10:04:15 volumio volumio[31804]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Jan 28 10:04:15 volumio volumio[31804]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 10:04:15 volumio volumio[31804]: info: [1769569455460] CoreMusicLibrary::Adding element Last_100 Jan 28 10:04:15 volumio volumio[31804]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 10:04:15 volumio volumio[31804]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 10:04:15 volumio volumio[31804]: info: [1769569455479] CoreMusicLibrary::Adding element Webradio Jan 28 10:04:15 volumio volumio[31804]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 10:04:15 volumio volumio[31804]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 10:04:15 volumio volumio[31804]: info: Initializing BBC Radios Jan 28 10:04:15 volumio volumio[31804]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Jan 28 10:04:15 volumio volumio[31804]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 10:04:15 volumio volumio[31804]: info: Creating Spotify config file Jan 28 10:04:15 volumio volumio[31804]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 10:04:15 volumio sudo[32013]: root : PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Jan 28 10:04:15 volumio sudo[32013]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=0) Jan 28 10:04:15 volumio sudo[32013]: pam_unix(sudo:session): session closed for user root Jan 28 10:04:16 volumio go-librespot[32002]: time="2026-01-28T10:04:16+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 10:04:16 volumio go-librespot[32002]: time="2026-01-28T10:04:16+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 10:04:16 volumio go-librespot[32002]: time="2026-01-28T10:04:16+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 10:04:16 volumio go-librespot[32002]: time="2026-01-28T10:04:16+07:00" level=info msg="zeroconf server listening on port 39333" Jan 28 10:04:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 10:04:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 10:04:16 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 10:04:16 volumio go-librespot[32002]: time="2026-01-28T10:04:16+07:00" level=debug msg="obtained new client token: AACZzjfZs/k0hj4C7Jbl4Lxls0fk9LsGlf68WUE1ivCYlQtZHxEK0mZvxJZnu6CBgwevD4s7fRvSL5uBDYd0wpeaLmfhZZKxC65LDgF05qBThq80B/45ZLtV4Mindvgd/WN2refQua3XNNs3TS0zNGuqFw8wmN+/QTUBjTgh8Fw6xhIxbX5PwCkBxDS98VSAkrGoY0wH1WuQSYAqJMMkudKZmkUv65iDx6TNVv51G4gVJQ0U/v2IZ3ZD1Xk=" Jan 28 10:04:16 volumio go-librespot[32002]: time="2026-01-28T10:04:16+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 10:04:16 volumio go-librespot[32002]: time="2026-01-28T10:04:16+07:00" level=debug msg="completed keyexchange" Jan 28 10:04:16 volumio go-librespot[32002]: time="2026-01-28T10:04:16+07:00" level=debug msg="completed challenge" Jan 28 10:04:16 volumio go-librespot[32002]: time="2026-01-28T10:04:16+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 10:04:16 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 10:04:16 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 10:04:16 volumio volumio[31927]: Starting albumart workers Jan 28 10:04:16 volumio volumio[31929]: Starting albumart workers Jan 28 10:04:16 volumio volumio[31804]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 10:04:17 volumio volumio[31804]: info: [1769569456998] CoreMusicLibrary::Adding element YouTube Music Jan 28 10:04:17 volumio volumio[31804]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 10:04:17 volumio volumio[31804]: Cannot find translation for source YouTube Music Jan 28 10:04:17 volumio volumio[31928]: Starting albumart workers Jan 28 10:04:17 volumio volumio[31804]: info: Volumio Calling Home Jan 28 10:04:17 volumio sudo[32032]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start roonbridge.service Jan 28 10:04:17 volumio sudo[32032]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 10:04:17 volumio sudo[32032]: pam_unix(sudo:session): session closed for user root Jan 28 10:04:17 volumio volumio[31804]: info: Discovery: adding 921648ed-0557-4d70-9927-1420682efcc7 Jan 28 10:04:17 volumio volumio[31804]: info: Discovery: Found device Volumio Jan 28 10:04:17 volumio volumio[31804]: info: CoreCommandRouter::volumioGetState Jan 28 10:04:17 volumio volumio[31804]: info: CorePlayQueue::getTrack 0 Jan 28 10:04:17 volumio volumio[31804]: info: Discovery: this is already registered, 921648ed-0557-4d70-9927-1420682efcc7 Jan 28 10:04:17 volumio volumio[31804]: info: Discovery: Found device Volumio Jan 28 10:04:17 volumio volumio[31804]: info: CoreCommandRouter::volumioGetState Jan 28 10:04:17 volumio volumio[31804]: info: CorePlayQueue::getTrack 0 Jan 28 10:04:18 volumio volumio[31804]: info: MPD Permissions set Jan 28 10:04:18 volumio volumio[31804]: info: MPD Permissions set Jan 28 10:04:18 volumio volumio[31804]: info: Upmpdcli Daemon Started Jan 28 10:04:18 volumio volumio[31804]: info: Spotify config file written Jan 28 10:04:18 volumio sudo[32038]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Jan 28 10:04:18 volumio sudo[32038]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 10:04:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 10:04:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 10:04:18 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 10:04:18 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 10:04:18 volumio go-librespot[32040]: go-librespot daemon starting... Jan 28 10:04:18 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 10:04:18 volumio sudo[32038]: pam_unix(sudo:session): session closed for user root Jan 28 10:04:18 volumio go-librespot[32041]: time="2026-01-28T10:04:18+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 10:04:18 volumio go-librespot[32041]: time="2026-01-28T10:04:18+07:00" level=debug msg="app state loaded" Jan 28 10:04:18 volumio go-librespot[32041]: time="2026-01-28T10:04:18+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 10:04:18 volumio volumio[31804]: 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 28 10:04:18 volumio volumio[31804]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 10:04:18 volumio volumio[31804]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 10:04:18 volumio volumio[31804]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 10:04:18 volumio volumio[31804]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 10:04:18 volumio volumio[31804]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 10:04:18 volumio volumio[31804]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 10:04:18 volumio volumio[31804]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 10:04:18 volumio volumio[31804]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 10:04:19 volumio volumio[31804]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 10:04:19 volumio volumio[31804]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 10:04:19 volumio volumio[31804]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 10:04:19 volumio volumio[31804]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 10:04:19 volumio volumio[31804]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 10:04:19 volumio volumio[31804]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 10:04:19 volumio volumio[31804]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 10:04:19 volumio volumio[31804]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 10:04:19 volumio volumio[31804]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 10:04:19 volumio volumio[31804]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 10:04:19 volumio volumio[31804]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 10:04:19 volumio volumio[31804]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Jan 28 10:04:19 volumio volumio[31804]: info: No need to fix Spotify hosts Jan 28 10:04:19 volumio go-librespot[32041]: time="2026-01-28T10:04:19+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 10:04:19 volumio go-librespot[32041]: time="2026-01-28T10:04:19+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 28 10:04:19 volumio go-librespot[32041]: time="2026-01-28T10:04:19+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 28 10:04:19 volumio go-librespot[32041]: time="2026-01-28T10:04:19+07:00" level=info msg="zeroconf server listening on port 37563" Jan 28 10:04:19 volumio go-librespot[32041]: time="2026-01-28T10:04:19+07:00" level=debug msg="obtained new client token: AACB0e24GMWLD5u6QuoRDTOBYNU9ag931pttUHJofgZBm31l7f2ZGmcAPEyN8ju7oMrChAm+2jimOqIXfsfqy32Rn/rR2lMRifwNy0zWIWmVYKXk+N8iQa7lnxNI97sA6tismlSBDtkAfioc7us7sf/Yb6wg0qeU+SDaAHnBqvahXsBrclT1P8/52SesEEHFMbqML1MOi/plVgl3UvyoWPIuAPfweIk+NpNaT3L5uXOOh8GwLI3YzaASmn8=" Jan 28 10:04:19 volumio volumio[31804]: info: Volumio called home Jan 28 10:04:19 volumio go-librespot[32041]: time="2026-01-28T10:04:19+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 10:04:19 volumio go-librespot[32041]: time="2026-01-28T10:04:19+07:00" level=debug msg="completed keyexchange" Jan 28 10:04:19 volumio go-librespot[32041]: time="2026-01-28T10:04:19+07:00" level=debug msg="completed challenge" Jan 28 10:04:19 volumio volumio[31804]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 28 10:04:19 volumio volumio[31804]: SPOTIFY: BQCg4JUzcPYypbnMhW1kexJ7m_jaP6KpM8b6VDuFo2JZDJL839D4FBwIMH48q-OuuRzzcUDBy-CASsZP6gSXhY3KnFTZYuuJYX7dUXTJubvzofpxl4SmD_2esHZdhde0n7PomfLZnUgIGuXDnUjwStqZ8pRS0lNAA6syxkjDRQ1KpDrSX8xu1BrLlU8hA3Pphxw6tP8CrbL5aPcNYp6enrN0v0XCiz4CkgmMFmJXSaNBJmEKuPmGxbCoNNehDQD4jVvj-P-eksHaQVxc5iSrw3NQsUoPokSyTiezcSoOGDzzDcyTMx8lkEz3 Jan 28 10:04:19 volumio volumio[31804]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Jan 28 10:04:19 volumio volumio[31804]: info: New Spotify access token = BQCg4JUzcPYypbnMhW1kexJ7m_jaP6KpM8b6VDuFo2JZDJL839D4FBwIMH48q-OuuRzzcUDBy-CASsZP6gSXhY3KnFTZYuuJYX7dUXTJubvzofpxl4SmD_2esHZdhde0n7PomfLZnUgIGuXDnUjwStqZ8pRS0lNAA6syxkjDRQ1KpDrSX8xu1BrLlU8hA3Pphxw6tP8CrbL5aPcNYp6enrN0v0XCiz4CkgmMFmJXSaNBJmEKuPmGxbCoNNehDQD4jVvj-P-eksHaQVxc5iSrw3NQsUoPokSyTiezcSoOGDzzDcyTMx8lkEz3 Jan 28 10:04:19 volumio volumio[31804]: info: Spotify credentials grant success - running version from March 24, 2019 Jan 28 10:04:19 volumio go-librespot[32041]: time="2026-01-28T10:04:19+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 10:04:19 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 10:04:19 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 10:04:19 volumio volumio[31804]: info: Starting Shairport Sync Jan 28 10:04:19 volumio volumio[31804]: info: Starting Shairport Sync Jan 28 10:04:19 volumio volumio[31804]: info: Starting Shairport Sync Jan 28 10:04:20 volumio sudo[32078]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 10:04:20 volumio sudo[32078]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 10:04:20 volumio sudo[32080]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 10:04:20 volumio sudo[32083]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Jan 28 10:04:20 volumio sudo[32083]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 10:04:20 volumio sudo[32080]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 10:04:20 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 28 10:04:20 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 28 10:04:20 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 10:04:20 volumio systemd[1]: shairport-sync.service: Consumed 2.398s CPU time. Jan 28 10:04:20 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 10:04:20 volumio sudo[32078]: pam_unix(sudo:session): session closed for user root Jan 28 10:04:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 10:04:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 10:04:20 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 10:04:20 volumio systemd[1]: Stopping shairport-sync.service - Shairport Sync - AirPlay Audio Receiver... Jan 28 10:04:20 volumio systemd[1]: shairport-sync.service: Deactivated successfully. Jan 28 10:04:20 volumio systemd[1]: Stopped shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 10:04:20 volumio volumio[31804]: info: Shairport-Sync Started Jan 28 10:04:20 volumio volumio[31804]: Error adding Membership: Error: addMembership EINVAL Jan 28 10:04:20 volumio systemd[1]: Started shairport-sync.service - Shairport Sync - AirPlay Audio Receiver. Jan 28 10:04:20 volumio sudo[32080]: pam_unix(sudo:session): session closed for user root Jan 28 10:04:20 volumio sudo[32083]: pam_unix(sudo:session): session closed for user root Jan 28 10:04:20 volumio volumio[31804]: info: CoreCommandRouter::volumioGetState Jan 28 10:04:20 volumio volumio[31804]: info: CorePlayQueue::getTrack 0 Jan 28 10:04:20 volumio volumio[31804]: info: Shairport-Sync Started Jan 28 10:04:20 volumio volumio[31804]: info: Shairport-Sync Started Jan 28 10:04:20 volumio volumio[31804]: 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 28 10:04:20 volumio volumio[31804]: info: Spotify Successfully logged in Jan 28 10:04:20 volumio volumio[31804]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Jan 28 10:04:20 volumio volumio[31804]: info: [1769569460754] CoreMusicLibrary::Adding element Spotify Jan 28 10:04:20 volumio volumio[31804]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Jan 28 10:04:20 volumio volumio[31804]: Cannot find translation for source YouTube Music Jan 28 10:04:20 volumio volumio[31804]: Cannot find translation for source Spotify Jan 28 10:04:21 volumio volumio[31804]: info: [yt-cast-receiver] DIAL server listening on port 8098 Jan 28 10:04:21 volumio volumio[31804]: info: CoreCommandRouter::volumioRetrievevolume Jan 28 10:04:21 volumio volumio[31804]: info: VolumeController:: Volume=100 Mute =false Jan 28 10:04:21 volumio volumio[31804]: info: CoreCommandRouter::volumioGetState Jan 28 10:04:21 volumio volumio[31804]: info: CorePlayQueue::getTrack 0 Jan 28 10:04:21 volumio volumio[31804]: info: CoreStateMachine::pushState Jan 28 10:04:21 volumio volumio[31804]: info: CorePlayQueue::getTrack 0 Jan 28 10:04:21 volumio volumio[31804]: info: CoreCommandRouter::volumioPushState Jan 28 10:04:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 10:04:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 10:04:22 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 10:04:22 volumio volumio[31804]: info: go-librespot daemon successfully initialized Jan 28 10:04:22 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 19. Jan 28 10:04:22 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 10:04:23 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 10:04:23 volumio go-librespot[32119]: go-librespot daemon starting... Jan 28 10:04:23 volumio mpd[32030]: 2026-01-28T10:04:23 decoder: Decoder plugin "wildmidi" is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Jan 28 10:04:23 volumio systemd[1]: Started mpd.service - Music Player Daemon. Jan 28 10:04:23 volumio sudo[31992]: pam_unix(sudo:session): session closed for user root Jan 28 10:04:23 volumio sudo[31982]: pam_unix(sudo:session): session closed for user root Jan 28 10:04:23 volumio go-librespot[32120]: time="2026-01-28T10:04:23+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 10:04:23 volumio go-librespot[32120]: time="2026-01-28T10:04:23+07:00" level=debug msg="app state loaded" Jan 28 10:04:23 volumio go-librespot[32120]: time="2026-01-28T10:04:23+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 10:04:23 volumio volumio[31804]: error: MPD error: The expression evaluated to a falsy value: Jan 28 10:04:23 volumio volumio[31804]: assert.ok(self.idling) Jan 28 10:04:23 volumio volumio[31804]: error: The expression evaluated to a falsy value: Jan 28 10:04:23 volumio volumio[31804]: assert.ok(self.idling) Jan 28 10:04:23 volumio volumio[31804]: info: MPD running with PID32030 Jan 28 10:04:23 volumio volumio[31804]: ,establishing connection Jan 28 10:04:23 volumio volumio[31804]: error: updateQueue error: null Jan 28 10:04:23 volumio volumio[31804]: info: Completed starting Core Plugins Jan 28 10:04:23 volumio volumio[31804]: info: ------------------------------------------- Jan 28 10:04:23 volumio volumio[31804]: info: ----- MyVolumio plugins startup ---- Jan 28 10:04:23 volumio volumio[31804]: info: ------------------------------------------- Jan 28 10:04:23 volumio volumio[31804]: info: [MyVolumio PluginManager] Fetching plans data.... Jan 28 10:04:23 volumio volumio[31804]: error: updateQueue error: null Jan 28 10:04:23 volumio go-librespot[32120]: time="2026-01-28T10:04:23+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 10:04:23 volumio go-librespot[32120]: time="2026-01-28T10:04:23+07:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Jan 28 10:04:23 volumio go-librespot[32120]: time="2026-01-28T10:04:23+07:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Jan 28 10:04:23 volumio go-librespot[32120]: time="2026-01-28T10:04:23+07:00" level=info msg="zeroconf server listening on port 40833" Jan 28 10:04:23 volumio go-librespot[32120]: time="2026-01-28T10:04:23+07:00" level=debug msg="obtained new client token: AAA3BG28i83aT6SjYW4sfHaICFaR0Gl2ssmnBK4mbcDEc4JkSBf0R6XwQAdux/Tr2ESszCtpri3UL/KBQtp7aSC3QxpVNtuqYfWda0uddSTUAD5tpYy5fY+UkJsHCLmCKGTMAVgbWxCw/96pdMXT1mFdknePOdwmnoiQBacgUhPmt5wPsmgCRpEcjikItU39vA2MAVMfFGJ2kz+H7R4m/XakVkoELqboU0cTPnr3v9USed2TFCF3k10z7w0=" Jan 28 10:04:24 volumio go-librespot[32120]: time="2026-01-28T10:04:24+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 10:04:24 volumio go-librespot[32120]: time="2026-01-28T10:04:24+07:00" level=debug msg="completed keyexchange" Jan 28 10:04:24 volumio go-librespot[32120]: time="2026-01-28T10:04:24+07:00" level=debug msg="completed challenge" Jan 28 10:04:24 volumio go-librespot[32120]: time="2026-01-28T10:04:24+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 28 10:04:24 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 10:04:24 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 10:04:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 10:04:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 10:04:24 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 10:04:25 volumio volumio[31804]: info: Initializing connection to go-librespot Websocket Jan 28 10:04:25 volumio volumio[31804]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 10:04:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 10:04:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 10:04:26 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 10:04:27 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 20. Jan 28 10:04:27 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 10:04:27 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 10:04:27 volumio go-librespot[32131]: go-librespot daemon starting... Jan 28 10:04:27 volumio go-librespot[32132]: time="2026-01-28T10:04:27+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 10:04:27 volumio go-librespot[32132]: time="2026-01-28T10:04:27+07:00" level=debug msg="app state loaded" Jan 28 10:04:27 volumio go-librespot[32132]: time="2026-01-28T10:04:27+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 10:04:27 volumio go-librespot[32132]: time="2026-01-28T10:04:27+07:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-guc3.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Jan 28 10:04:27 volumio go-librespot[32132]: time="2026-01-28T10:04:27+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 28 10:04:27 volumio go-librespot[32132]: time="2026-01-28T10:04:27+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 28 10:04:27 volumio go-librespot[32132]: time="2026-01-28T10:04:27+07:00" level=info msg="zeroconf server listening on port 41693" Jan 28 10:04:28 volumio go-librespot[32132]: time="2026-01-28T10:04:28+07:00" level=debug msg="obtained new client token: AACOaWZ1OsxxKbk6KzTSKRbF1IK6v5Bgk3s/DyJ3E1MpdRU9zoRFbZDjTxRoyNYb7C9qmtwSu156hBqWL4sFlCk+1CfiAR/2o/2er3KOpSIQ3UAK7MqELmRq1/qb/w8F9RirH+P7JymrlF56R4r/N0/SlPnPYhAFGb1fMY7uP5RghJkz0HvyEjcAO4EReT3IX7FT6BxUupEiHGwtU907FSjS1LzG+pm7srk4ATJmVqVaTNQnvbCsO/MR" Jan 28 10:04:28 volumio go-librespot[32132]: time="2026-01-28T10:04:28+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 10:04:28 volumio volumio[31804]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Jan 28 10:04:28 volumio go-librespot[32132]: time="2026-01-28T10:04:28+07:00" level=debug msg="completed keyexchange" Jan 28 10:04:28 volumio go-librespot[32132]: time="2026-01-28T10:04:28+07:00" level=debug msg="completed challenge" Jan 28 10:04:28 volumio go-librespot[32132]: time="2026-01-28T10:04:28+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 10:04:28 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 10:04:28 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 10:04:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 10:04:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 10:04:28 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 10:04:28 volumio volumio[31804]: info: Initializing connection to go-librespot Websocket Jan 28 10:04:28 volumio volumio[31804]: info: Error connecting to go-librespot Websocket: Error: connect ECONNREFUSED 127.0.0.1:9879 Jan 28 10:04:30 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 10:04:30 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 10:04:30 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 10:04:31 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 21. Jan 28 10:04:31 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 10:04:31 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 10:04:31 volumio go-librespot[32139]: go-librespot daemon starting... Jan 28 10:04:31 volumio go-librespot[32140]: time="2026-01-28T10:04:31+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 10:04:31 volumio go-librespot[32140]: time="2026-01-28T10:04:31+07:00" level=debug msg="app state loaded" Jan 28 10:04:31 volumio go-librespot[32140]: time="2026-01-28T10:04:31+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 10:04:31 volumio volumio[31804]: info: Initializing connection to go-librespot Websocket Jan 28 10:04:31 volumio go-librespot[32140]: time="2026-01-28T10:04:31+07:00" level=debug msg="new websocket client" Jan 28 10:04:31 volumio volumio[31804]: info: Connection to go-librespot Websocket established Jan 28 10:04:32 volumio go-librespot[32140]: time="2026-01-28T10:04:32+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 28 10:04:32 volumio go-librespot[32140]: time="2026-01-28T10:04:32+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 28 10:04:32 volumio go-librespot[32140]: time="2026-01-28T10:04:32+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 28 10:04:32 volumio go-librespot[32140]: time="2026-01-28T10:04:32+07:00" level=info msg="zeroconf server listening on port 34801" Jan 28 10:04:32 volumio go-librespot[32140]: time="2026-01-28T10:04:32+07:00" level=debug msg="obtained new client token: AAD8CIshb+HhjiMHvV9HxkrsvlTCnCHXGHq3VQxnVRuXoktGT8vFTD4c32MG42GSwLcpeo8vsufKI1b2p8PmTkyOaZosEkmEq6I2jG6rpJd3RsKyA69Q6NGQBXBX6uaRYPQ6mEivrox3jgrZzrAAbMqpQcUo0cY7/ZpjWp2aPhz8alngmcoltD5Cx773EBqVnRYp441iOXZmfuazFmLo64/TcPOqiFIAUqRUEeuTt/WGhs5BjScWbkWRp+4=" Jan 28 10:04:32 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 10:04:32 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 10:04:32 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 10:04:32 volumio volumio[31804]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Jan 28 10:04:32 volumio volumio[31804]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Jan 28 10:04:32 volumio volumio[31804]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Jan 28 10:04:32 volumio volumio[31804]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Jan 28 10:04:32 volumio volumio[31804]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Jan 28 10:04:32 volumio volumio[31804]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Jan 28 10:04:32 volumio volumio[31804]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Jan 28 10:04:32 volumio volumio[31804]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Jan 28 10:04:32 volumio volumio[31804]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Jan 28 10:04:32 volumio volumio[31804]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Jan 28 10:04:32 volumio volumio[31804]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan premium Jan 28 10:04:32 volumio volumio[31804]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Jan 28 10:04:32 volumio volumio[31804]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Jan 28 10:04:32 volumio volumio[31804]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Jan 28 10:04:32 volumio volumio[31804]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Jan 28 10:04:32 volumio volumio[31804]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Jan 28 10:04:32 volumio volumio[31804]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Jan 28 10:04:32 volumio volumio[31804]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Jan 28 10:04:32 volumio volumio[31804]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Jan 28 10:04:32 volumio volumio[31804]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Jan 28 10:04:32 volumio volumio[31804]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Jan 28 10:04:32 volumio volumio[31804]: info: [MyVolumio PluginManager] Adding plugin qobuzconnect to plan superstar Jan 28 10:04:32 volumio volumio[31804]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Jan 28 10:04:32 volumio volumio[31804]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Jan 28 10:04:32 volumio volumio[31804]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Jan 28 10:04:32 volumio volumio[31804]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Jan 28 10:04:32 volumio volumio[31804]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Jan 28 10:04:32 volumio volumio[31804]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Jan 28 10:04:32 volumio volumio[31804]: info: Adding plugin bluetooth to MyMusic Plugins Jan 28 10:04:32 volumio volumio[31804]: info: Adding plugin multiroom to MyMusic Plugins Jan 28 10:04:32 volumio volumio[31804]: info: Adding plugin metavolumio to MyMusic Plugins Jan 28 10:04:32 volumio volumio[31804]: info: Adding plugin cd_controller to MyMusic Plugins Jan 28 10:04:32 volumio volumio[31804]: info: Adding plugin qobuzconnect to MyMusic Plugins Jan 28 10:04:32 volumio volumio[31804]: info: Adding plugin smart_inputs to MyMusic Plugins Jan 28 10:04:32 volumio volumio[31804]: info: Adding plugin tidalconnect to MyMusic Plugins Jan 28 10:04:32 volumio volumio[31804]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Jan 28 10:04:32 volumio go-librespot[32140]: time="2026-01-28T10:04:32+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 10:04:32 volumio go-librespot[32140]: time="2026-01-28T10:04:32+07:00" level=debug msg="completed keyexchange" Jan 28 10:04:32 volumio go-librespot[32140]: time="2026-01-28T10:04:32+07:00" level=debug msg="completed challenge" Jan 28 10:04:32 volumio go-librespot[32140]: time="2026-01-28T10:04:32+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 10:04:32 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 10:04:32 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 10:04:34 volumio volumio[31804]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Jan 28 10:04:34 volumio volumio[31804]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Jan 28 10:04:34 volumio volumio[31804]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 10:04:34 volumio volumio[31804]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Jan 28 10:04:34 volumio volumio[31804]: info: Starting MyVolumio Remote Streaming Endpoints Jan 28 10:04:34 volumio volumio[31804]: info: MyVolumio login type: Token Jan 28 10:04:34 volumio volumio[31804]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Jan 28 10:04:34 volumio volumio[31804]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Jan 28 10:04:34 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 10:04:34 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 10:04:34 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 10:04:35 volumio systemd[1]: go-librespot-daemon.service: Scheduled restart job, restart counter is at 22. Jan 28 10:04:35 volumio systemd[1]: Stopped go-librespot-daemon.service - go-librespot Daemon. Jan 28 10:04:35 volumio systemd[1]: Started go-librespot-daemon.service - go-librespot Daemon. Jan 28 10:04:35 volumio go-librespot[32162]: go-librespot daemon starting... Jan 28 10:04:35 volumio go-librespot[32163]: time="2026-01-28T10:04:35+07:00" level=info msg="running go-librespot 0.4.0" Jan 28 10:04:35 volumio go-librespot[32163]: time="2026-01-28T10:04:35+07:00" level=debug msg="app state loaded" Jan 28 10:04:35 volumio go-librespot[32163]: time="2026-01-28T10:04:35+07:00" level=info msg="api server listening on 127.0.0.1:9879" Jan 28 10:04:36 volumio volumio[31804]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Jan 28 10:04:36 volumio volumio[31804]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Jan 28 10:04:36 volumio volumio[31804]: info: Streaming services startup Jan 28 10:04:36 volumio volumio[31804]: info: Starting Streaming Daemon Jan 28 10:04:36 volumio sudo[32170]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Jan 28 10:04:36 volumio volumio[31804]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Jan 28 10:04:36 volumio sudo[32170]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Jan 28 10:04:36 volumio sudo[32170]: pam_unix(sudo:session): session closed for user root Jan 28 10:04:36 volumio volumio[31804]: info: Getting Spotify volume Jan 28 10:04:36 volumio volumio[31804]: info: Connection to go-librespot Websocket closed Jan 28 10:04:36 volumio volumio[31804]: error: Cannot start Volumio Streaming Daemon Jan 28 10:04:36 volumio volumio[31804]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Jan 28 10:04:36 volumio volumio[31804]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Jan 28 10:04:36 volumio volumio[31804]: 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 28 10:04:36 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 10:04:36 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 10:04:36 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 10:04:36 volumio go-librespot[32163]: time="2026-01-28T10:04:36+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 28 10:04:36 volumio go-librespot[32163]: time="2026-01-28T10:04:36+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 28 10:04:36 volumio go-librespot[32163]: time="2026-01-28T10:04:36+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 28 10:04:36 volumio go-librespot[32163]: time="2026-01-28T10:04:36+07:00" level=info msg="zeroconf server listening on port 41639" Jan 28 10:04:36 volumio volumio[31804]: info: CoreCommandRouter::volumioGetState Jan 28 10:04:36 volumio volumio[31804]: info: CorePlayQueue::getTrack 0 Jan 28 10:04:36 volumio volumio[31804]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Jan 28 10:04:36 volumio volumio[31804]: SPOTIFY: SPOTIFY VOLUME undefined Jan 28 10:04:36 volumio volumio[31804]: SPOTIFY: VOLUMIO VOLUME 100 Jan 28 10:04:36 volumio volumio[31804]: info: Aligning Spotify Volume to Volumio Volume Jan 28 10:04:36 volumio volumio[31804]: info: CoreCommandRouter::volumioGetState Jan 28 10:04:36 volumio volumio[31804]: info: CorePlayQueue::getTrack 0 Jan 28 10:04:36 volumio volumio[31804]: info: Setting Spotify Volume from Volumio: 100 Jan 28 10:04:36 volumio go-librespot[32163]: time="2026-01-28T10:04:36+07:00" level=debug msg="obtained new client token: AADFRFjy3l4/3mqtzlVVWC9j7DaXAHpe0GpsGOWCnY+E3I0VIiN+cNXtFXVKh7y6wVaWSICwGCI6RhecoJAIlRDVgC/bcg2Ctuyub8lD1b84iFib1WegDqQZy5jru50wSKiMNudbq+T6XjM8LQJsYanZbiV1CqM3IOA6ju8R6HIlu/vEhshMDKjjXndTnmj3T5A+zURcIK1Q8IuHQW4Aw4JOwqps7COOKVaNpgNRgdGnLSz9LZep6spPjbs=" Jan 28 10:04:36 volumio go-librespot[32163]: time="2026-01-28T10:04:36+07:00" level=debug msg="connected to ap-gae2.spotify.com:4070" Jan 28 10:04:36 volumio go-librespot[32163]: time="2026-01-28T10:04:36+07:00" level=debug msg="completed keyexchange" Jan 28 10:04:36 volumio go-librespot[32163]: time="2026-01-28T10:04:36+07:00" level=debug msg="completed challenge" Jan 28 10:04:36 volumio go-librespot[32163]: time="2026-01-28T10:04:36+07:00" level=fatal msg="failed running with username and spotify token" error="failed authenticating accesspoint with stored credentials: failed authenticating: accesspoint login failed: BadCredentials " Jan 28 10:04:37 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=exited, status=1/FAILURE Jan 28 10:04:37 volumio systemd[1]: go-librespot-daemon.service: Failed with result 'exit-code'. Jan 28 10:04:37 volumio volumio[31804]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 10:04:37 volumio volumio[31804]: Error: socket hang up Jan 28 10:04:37 volumio volumio[31804]: at connResetException (node:internal/errors:720:14) Jan 28 10:04:37 volumio volumio[31804]: at Socket.socketOnEnd (node:_http_client:519:23) Jan 28 10:04:37 volumio volumio[31804]: at Socket.emit (node:events:526:35) Jan 28 10:04:37 volumio volumio[31804]: at endReadableNT (node:internal/streams/readable:1376:12) Jan 28 10:04:37 volumio volumio[31804]: at process.processTicksAndRejections (node:internal/process/task_queues:82:21) { Jan 28 10:04:37 volumio volumio[31804]: code: 'ECONNRESET', Jan 28 10:04:37 volumio volumio[31804]: response: undefined Jan 28 10:04:37 volumio volumio[31804]: } Jan 28 10:04:37 volumio volumio[31804]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Jan 28 10:04:38 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:113::MPDCli::openconn: mpd_connection_new failed: Failed to resolve host name Jan 28 10:04:38 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:389::MPDCli::updStatus: no connection Jan 28 10:04:38 volumio upmpdcli[1383]: :2:../src/mpdcli.cxx:243::MPDCli::eventloop: mpd_run_idle_mask returned 0 Jan 28 10:04:38 volumio sudo[32192]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-01-28 10:03' Jan 28 10:04:38 volumio sudo[32192]: 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"